From 23732039de840edff253c2a66d24f1e76e3018d7 Mon Sep 17 00:00:00 2001 From: Evgeny Date: Wed, 10 Jun 2026 11:18:55 +0300 Subject: [PATCH] =?UTF-8?q?SOCKET=20=D1=81=D0=BE=D0=BE=D0=B1=D1=89=D0=B5?= =?UTF-8?q?=D0=BD=D0=B8=D1=8F=20=D0=B6=D0=B8=D0=B7=D0=BD=D0=B5=D0=BD=D0=BD?= =?UTF-8?q?=D0=BE=D0=B3=D0=BE=20=D1=86=D0=B8=D0=BA=D0=BB=D0=B0:=20INFO?= =?UTF-8?q?=E2=86=92DEBUG?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- lib/tcp_io.c | 16 ++++++++-------- src/proxy/tcp_proxy_server.c | 30 +++++++++++++++--------------- 2 files changed, 23 insertions(+), 23 deletions(-) diff --git a/lib/tcp_io.c b/lib/tcp_io.c index 9dde20e0..0a9d7222 100644 --- a/lib/tcp_io.c +++ b/lib/tcp_io.c @@ -91,14 +91,14 @@ struct tcp_conn* tcp_conn_create( if (getpeername(sock, (struct sockaddr*)&addr, &alen) == 0) tc->connected = 1; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_conn_create: fd=%d entry=%zu chunk=%zu hw=%d lw=%d connected=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_conn_create: fd=%d entry=%zu chunk=%zu hw=%d lw=%d connected=%d", (int)sock, entry_data_size, write_chunk_size, read_high_water, read_low_water, tc->connected); return tc; } void tcp_conn_destroy(struct tcp_conn* tc) { if (!tc) return; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_conn_destroy: fd=%d connected=%d error=%d fin_remote=%d fin_local=%d closed=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_conn_destroy: fd=%d connected=%d error=%d fin_remote=%d fin_local=%d closed=%d", (int)tc->sock, tc->connected, tc->error, tc->fin_remote, tc->fin_local, tc->closed); if (tc->socket_id) { @@ -202,7 +202,7 @@ static void read_cb(socket_t sock, void* arg) { memory_pool_free(tc->data_pool, buf); queue_entry_free(e); tc->fin_remote = 1; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: FIN fd=%d", (int)tc->sock); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: FIN fd=%d", (int)tc->sock); uasync_set_socket_read(tc->ua, tc->socket_id, 0); queue_waiter_cancel(tc->read_queue, &tc->read_waiter); if (tc->read_queue->count == 0) { @@ -288,14 +288,14 @@ static void write_queue_fetch_cb(struct ll_queue* q, void* arg) { if (e->len == 0) { if (!e->dgram) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: CLOSE fd=%d", (int)tc->sock); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: CLOSE fd=%d", (int)tc->sock); queue_entry_free(e); queue_resume_callback(q); uasync_remove_socket_t(tc->ua, tc->sock); socket_close_wrapper(tc->sock); tc->socket_id = NULL; tc->sock = SOCKET_INVALID; tc->closed = 1; if (tc->on_closed) tc->on_closed(tc, tc->arg); } else if (e->dgram == &tcp_fin_sentinel) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: FIN fd=%d", (int)tc->sock); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: FIN fd=%d", (int)tc->sock); queue_entry_free(e); queue_resume_callback(q); shutdown(tc->sock, SHUT_WR); tc->fin_local = 1; @@ -365,7 +365,7 @@ static void write_cb(socket_t sock, void* arg) { socklen_t len = sizeof(err); if (getsockopt(tc->sock, SOL_SOCKET, SO_ERROR, &err, &len) == 0 && err == 0) { tc->connected = 1; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: connect ok fd=%d", (int)tc->sock); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: connect ok fd=%d", (int)tc->sock); } else { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_io: connect fail fd=%d err=%d", (int)tc->sock, err); tcp_conn_handle_error(tc, err ? err : -1); @@ -403,7 +403,7 @@ int tcp_conn_push_fin(struct tcp_conn* tc) { struct ll_entry* e = queue_entry_new_from_pool(tc->entry_pool); if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_io: push_fin entry_pool exhausted fd=%d", (int)tc->sock); return -1; } e->dgram = (uint8_t*)&tcp_fin_sentinel; e->len = 0; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: push_fin fd=%d wq=%d", (int)tc->sock, tc->write_queue->count + 1); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: push_fin fd=%d wq=%d", (int)tc->sock, tc->write_queue->count + 1); queue_data_put(tc->write_queue, e); return 0; } @@ -414,7 +414,7 @@ int tcp_conn_push_close(struct tcp_conn* tc) { struct ll_entry* e = queue_entry_new_from_pool(tc->entry_pool); if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_io: push_close entry_pool exhausted fd=%d", (int)tc->sock); return -1; } e->dgram = NULL; e->len = 0; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "tcp_io: push_close fd=%d wq=%d", (int)tc->sock, tc->write_queue->count + 1); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "tcp_io: push_close fd=%d wq=%d", (int)tc->sock, tc->write_queue->count + 1); queue_data_put(tc->write_queue, e); return 0; } diff --git a/src/proxy/tcp_proxy_server.c b/src/proxy/tcp_proxy_server.c index cc217629..31ec9854 100644 --- a/src/proxy/tcp_proxy_server.c +++ b/src/proxy/tcp_proxy_server.c @@ -114,16 +114,16 @@ static void on_fin_cb(struct tcp_conn* tc, void* arg) { if (rc->cli_closed) return; int pend = write_pending(tc); if (tc->fin_local) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x fin_local=%d — both FINs, closing", - (int)tc->sock, rc->stream_id, tc->fin_local); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x fin_local=%d — both FINs, closing", + (int)tc->sock, rc->stream_id, tc->fin_local); send_close(rc); tcp_conn_push_close(tc); } else if (pend) { tcp_conn_set_flushed(tc, on_flushed_cb); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x write_pend=%d → deferred", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x write_pend=%d → deferred", (int)tc->sock, rc->stream_id, pend); } else { send_fin(rc); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x → relay now", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:DST_FIN fd=%d sid=%08x → relay now", (int)tc->sock, rc->stream_id); } } @@ -132,7 +132,7 @@ static void on_flushed_cb(struct tcp_conn* tc, void* arg) { struct tcp_proxy_server_conn* rc = (struct tcp_proxy_server_conn*)arg; if (rc->cli_closed) return; if (tc->fin_local) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:FLUSHED fd=%d sid=%08x fin_local=%d — both FINs, closing", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FLUSHED fd=%d sid=%08x fin_local=%d — both FINs, closing", (int)tc->sock, rc->stream_id, tc->fin_local); send_close(rc); tcp_conn_push_close(tc); return; } @@ -141,7 +141,7 @@ static void on_flushed_cb(struct tcp_conn* tc, void* arg) { static void on_closed_cb(struct tcp_conn* tc, void* arg) { struct tcp_proxy_server_conn* rc = (struct tcp_proxy_server_conn*)arg; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSED fd=%d sid=%08x — freeing", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSED fd=%d sid=%08x — freeing", tc ? (int)tc->sock : -1, rc->stream_id); tcp_proxy_server_conn_free(rc); } @@ -168,7 +168,7 @@ static void diag_timer_cb(void* arg) { getsockopt(tc->sock, SOL_SOCKET, SO_RCVBUF, &rcv_buf, &optlen); getsockopt(tc->sock, SOL_SOCKET, SO_SNDBUF, &snd_buf, &optlen); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:DIAG fd=%d sid=%08x conn=%d fin=%d " "rq=%d(%zub) wq=%d(%zub) wbuf=%s " "ent_f=%d dat_f=%d tcp_rb=%zu tcp_sb=%zu", @@ -208,7 +208,7 @@ static void read_queue_drain_cb(struct ll_queue* q, void* arg) { if (ret == 0) { queue_resume_callback(q); } else { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:BACKPRESSURE fd=%d sid=%08x — pausing drain", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:BACKPRESSURE fd=%d sid=%08x — pausing drain", (int)rc->tc->sock, rc->stream_id); etcp_router_on_send_ready(inst, rc->peer_node_id, ETCP_ID_TCP_PROXY_CLIENT, &rc->pause_waiter, pause_resume_cb, rc); @@ -235,14 +235,14 @@ static int conn_total(struct tcp_proxy_server_conn* rc) { void tcp_proxy_server_conn_free(struct tcp_proxy_server_conn* rc) { if (!rc) return; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:FREE enter rc=%p freed=%d sid=%08x", (void*)rc, rc->freed, rc->stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE enter rc=%p freed=%d sid=%08x", (void*)rc, rc->freed, rc->stream_id); if (rc->freed) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "SOCK:FREE double rc=%p — IGNORED", (void*)rc); return; } rc->freed = 1; int total = conn_total(rc); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:FREE fd=%d sid=%08x total=%d cli_closed=%d fin=%d error=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE fd=%d sid=%08x total=%d cli_closed=%d fin=%d error=%d", rc->tc ? (int)rc->tc->sock : -1, rc->stream_id, total, rc->cli_closed, rc->tc ? rc->tc->fin_remote : 0, rc->tc ? rc->tc->error : 0); if (rc->close_pending && rc->ctx && rc->ctx->inst) { rc->close_pending = 0; @@ -257,7 +257,7 @@ void tcp_proxy_server_conn_free(struct tcp_proxy_server_conn* rc) { if (rc->close_timer) { uasync_cancel_timeout(rc->ua, rc->close_timer); rc->close_timer = NULL; } if (rc->diag_timer) { uasync_cancel_timeout(rc->ua, rc->diag_timer); rc->diag_timer = NULL; } if (rc->ctx && rc->ctx->inst) etcp_router_cancel_send_ready(rc->ctx->inst, rc->peer_node_id, ETCP_ID_TCP_PROXY_CLIENT, &rc->pause_waiter); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:FREE u_free rc=%p", (void*)rc); + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE u_free rc=%p", (void*)rc); u_free(rc); } @@ -287,7 +287,7 @@ int tcp_proxy_server_handle_connect(struct UTUN_INSTANCE* inst, struct ll_entry* socket_t sock = socket(AF_INET, SOCK_STREAM, 0); if (sock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy server: socket() failed"); u_free(rc); queue_dgram_free(entry); queue_entry_free(entry); return -1; } ctx->conn_count++; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:NEW fd=%d sid=%08x dest=%d.%d.%d.%d:%d total=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:NEW fd=%d sid=%08x dest=%d.%d.%d.%d:%d total=%d", (int)sock, stream_id, dest_ip[0],dest_ip[1],dest_ip[2],dest_ip[3],ntohs(dest_port), ctx->conn_count); socket_set_nonblocking(sock); @@ -352,7 +352,7 @@ void tcp_proxy_server_handle_close(struct UTUN_INSTANCE* inst, uint32_t stream_i struct tcp_proxy_server* ctx = &inst->tcp_proxy_server; struct tcp_proxy_server_conn* rc = tcp_proxy_server_find_conn(ctx, stream_id); if (!rc) { DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "TCP proxy server: CLOSE sid=%08x — no conn", stream_id); return; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSE_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSE_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", rc->tc ? (int)rc->tc->sock : -1, stream_id, conn_total(rc), rc->tc ? rc->tc->fin_remote : 0, rc->tc ? write_pending(rc->tc) : 0); rc->cli_closed = 1; @@ -374,7 +374,7 @@ void tcp_proxy_server_handle_error(struct UTUN_INSTANCE* inst, uint32_t stream_i struct tcp_proxy_server* ctx = &inst->tcp_proxy_server; struct tcp_proxy_server_conn* rc = tcp_proxy_server_find_conn(ctx, stream_id); if (!rc) { DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy server: ERROR sid=%08x — no conn", stream_id); return; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:ERROR_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:ERROR_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", rc->tc ? (int)rc->tc->sock : -1, stream_id, conn_total(rc), rc->tc ? rc->tc->fin_remote : 0, rc->tc ? write_pending(rc->tc) : 0); tcp_proxy_server_handle_close(inst, stream_id); @@ -385,7 +385,7 @@ void tcp_proxy_server_handle_fin(struct UTUN_INSTANCE* inst, uint32_t stream_id) struct tcp_proxy_server* ctx = &inst->tcp_proxy_server; struct tcp_proxy_server_conn* rc = tcp_proxy_server_find_conn(ctx, stream_id); if (!rc || !rc->tc || !rc->tc->connected) return; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCK:FIN_RECV fd=%d sid=%08x — pushing FIN to wq", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FIN_RECV fd=%d sid=%08x — pushing FIN to wq", (int)rc->tc->sock, stream_id); tcp_conn_push_fin(rc->tc); }