From 869f7c60d5af8cb673f9203df8e8dfcaaaa7a420 Mon Sep 17 00:00:00 2001 From: Evgeny Date: Sun, 9 Aug 2026 16:31:21 +0300 Subject: [PATCH] debug: add PROXY category, move all proxy logs to it --- lib/debug_config.c | 1 + lib/debug_config.h | 3 +- src/proxy/icmp_proxy.c | 34 +++++----- src/proxy/socks_proxy.c | 128 +++++++++++++++++------------------ src/proxy/tcp_proxy_client.c | 94 ++++++++++++------------- src/proxy/tcp_proxy_server.c | 82 +++++++++++----------- src/proxy/udp_proxy.c | 6 +- 7 files changed, 175 insertions(+), 173 deletions(-) diff --git a/lib/debug_config.c b/lib/debug_config.c index e34df93f..ab1e5dac 100644 --- a/lib/debug_config.c +++ b/lib/debug_config.c @@ -126,6 +126,7 @@ static const struct { {"etcp_dump", DEBUG_CATEGORY_ETCP_DUMP}, {"chat_sync", DEBUG_CATEGORY_CHAT_SYNC}, {"member_sync", DEBUG_CATEGORY_MEMBER_SYNC}, + {"proxy", DEBUG_CATEGORY_PROXY}, {"all", DEBUG_CATEGORY_ALL}, {NULL, DEBUG_CATEGORY_NONE} }; diff --git a/lib/debug_config.h b/lib/debug_config.h index 1e80cdc6..31f3560d 100644 --- a/lib/debug_config.h +++ b/lib/debug_config.h @@ -66,7 +66,8 @@ typedef int debug_category_t; // #define DEBUG_CATEGORY_CONNECTIVITY 25 (unused, removed) #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_COUNT 28 // Total number of categories +#define DEBUG_CATEGORY_PROXY 28 // Proxy modules (SOCKS5, TCP, UDP, ICMP) +#define DEBUG_CATEGORY_COUNT 29 // Total number of categories #define DEBUG_CATEGORY_ALL (-1) // special value for all categories /* Debug configuration structure */ diff --git a/src/proxy/icmp_proxy.c b/src/proxy/icmp_proxy.c index 35fed5f4..fb1423bc 100644 --- a/src/proxy/icmp_proxy.c +++ b/src/proxy/icmp_proxy.c @@ -81,13 +81,13 @@ static int exit_send_echo(struct UTUN_INSTANCE* inst, uint64_t client_node_id, while (sum >> 16) sum = (sum & 0xFFFF) + (sum >> 16); icmp_hdr->icmp_cksum = ~(uint16_t)sum; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: sendto dst=0x%08x id=0x%04x seq=%u len=%zu", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: sendto dst=0x%08x id=0x%04x seq=%u len=%zu", dst_ip, echo_id, echo_seq, icmp_len); struct sockaddr_in addr = {.sin_family = AF_INET, .sin_addr = {.s_addr = dst_ip}}; ssize_t n = sendto(g_icmp_ctx->raw_sock, buf, icmp_len, 0, (struct sockaddr*)&addr, sizeof(addr)); u_free(buf); - if (n < 0) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: sendto failed: %s", strerror(errno)); return -1; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: sendto sent %zd bytes", n); + if (n < 0) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: sendto failed: %s", strerror(errno)); return -1; } + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: sendto sent %zd bytes", n); struct icmp_request* r = u_calloc(1, sizeof(struct icmp_request)); if (!r) return 0; @@ -109,7 +109,7 @@ static void raw_read_cb(socket_t sock, void* arg) { uint8_t buf[65536]; struct sockaddr_in from; socklen_t flen = sizeof(from); ssize_t n = recvfrom(g_icmp_ctx->raw_sock, buf, sizeof(buf), 0, (struct sockaddr*)&from, &flen); - if (n <= 0) { if (n < 0) DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: recvfrom error: %s", strerror(errno)); return; } + if (n <= 0) { if (n < 0) DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: recvfrom error: %s", strerror(errno)); return; } if (n < (ssize_t)(sizeof(struct ip) + ICMP_MINLEN)) return; struct ip* ip_hdr = (struct ip*)buf; @@ -120,11 +120,11 @@ static void raw_read_cb(socket_t sock, void* arg) { if (icmp_hdr->icmp_type != ICMP_ECHOREPLY) return; struct icmp_request* r = req_find_by_id(g_icmp_ctx->pending, icmp_hdr->icmp_id, icmp_hdr->icmp_seq); - if (!r) { DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "icmp_proxy: unclaimed echo reply id=0x%04x seq=%u from=0x%08x", + if (!r) { DEBUG_WARN(DEBUG_CATEGORY_PROXY, "icmp_proxy: unclaimed echo reply id=0x%04x seq=%u from=0x%08x", icmp_hdr->icmp_id, icmp_hdr->icmp_seq, from.sin_addr.s_addr); return; } { struct icmp_request** rp = &g_icmp_ctx->pending; while (*rp) { if (*rp == r) { *rp = r->next; break; } rp = &(*rp)->next; } } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: echo reply id=0x%04x seq=%u from=0x%08x", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: echo reply id=0x%04x seq=%u from=0x%08x", icmp_hdr->icmp_id, icmp_hdr->icmp_seq, from.sin_addr.s_addr); size_t payload_len = n - ip_hdr_len - ICMP_MINLEN; @@ -145,8 +145,8 @@ static void raw_read_cb(socket_t sock, void* arg) { if (payload_len > 0) memcpy(e->dgram + ICMP_PROXY_HDR_SIZE, payload, payload_len); e->len = ICMP_PROXY_HDR_SIZE + payload_len; int ret = etcp_route_send(g_icmp_ctx->inst, TOPO_GROUP_UTUN, r->client_node_id, e, 0); - if (ret != 0) DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: etcp_route_send reply failed: %d", ret); - else DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: reply forwarded to client %016llx", (unsigned long long)r->client_node_id); + if (ret != 0) DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: etcp_route_send reply failed: %d", ret); + else DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: reply forwarded to client %016llx", (unsigned long long)r->client_node_id); u_free(r); } @@ -168,7 +168,7 @@ static void exit_handle_request(struct ETCP_CONN* conn, struct ll_entry* entry) if (g_icmp_ctx->raw_sock != SOCKET_INVALID) { exit_send_echo(inst, client_node_id, dst_ip, orig_src_ip, echo_id, echo_seq, payload, payload_len); } else if (g_icmp_ctx->test_loopback) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: test loopback reply to 0x%08x", dst_ip); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: test loopback reply to 0x%08x", dst_ip); struct ll_entry* e = queue_entry_new(0); if (e) { e->dgram = u_malloc(ICMP_PROXY_HDR_SIZE + payload_len); @@ -186,7 +186,7 @@ static void exit_handle_request(struct ETCP_CONN* conn, struct ll_entry* entry) } else queue_entry_free(e); } } else { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: no raw socket, dropping echo request to 0x%08x", dst_ip); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: no raw socket, dropping echo request to 0x%08x", dst_ip); } drop: @@ -205,7 +205,7 @@ static void client_handle_reply(struct ETCP_CONN* conn, struct ll_entry* entry) memcpy(&orig_src_ip, entry->dgram + 14, 4); memcpy(&echo_id, entry->dgram + 18, 2); memcpy(&echo_seq, entry->dgram + 20, 2); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: client got reply id=0x%04x seq=%u from=0x%08x dst=0x%08x", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: client got reply id=0x%04x seq=%u from=0x%08x dst=0x%08x", echo_id, echo_seq, src_ip, orig_src_ip); struct UTUN_INSTANCE* inst = conn ? conn->instance : (g_icmp_ctx ? g_icmp_ctx->inst : NULL); icmp_proxy_deliver_reply(inst, orig_src_ip, src_ip, echo_id, echo_seq, @@ -257,7 +257,7 @@ int icmp_proxy_deliver_reply(struct UTUN_INSTANCE* inst, uint32_t dst_ip, uint32_t src_ip, uint16_t echo_id, uint16_t echo_seq, const uint8_t* payload, size_t payload_len) { if (!inst || !inst->tcp_proxy_client || !inst->tcp_proxy_client->tun) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: deliver_reply failed — no %s", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: deliver_reply failed — no %s", !inst ? "inst" : !inst->tcp_proxy_client ? "tcp_proxy_client" : "TUN"); return -1; } @@ -294,7 +294,7 @@ int icmp_proxy_deliver_reply(struct UTUN_INSTANCE* inst, e->dgram = u_malloc(1 + pkt_len); e->dgram[0] = 4; memcpy(e->dgram + 1, pkt, pkt_len); e->len = 1 + pkt_len; u_free(pkt); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: reply delivered to TUN id=0x%04x seq=%u", echo_id, echo_seq); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: reply delivered to TUN id=0x%04x seq=%u", echo_id, echo_seq); queue_data_put(tun->input_queue, e); return 0; } @@ -338,9 +338,9 @@ int icmp_proxy_init(struct UTUN_INSTANCE* inst, struct UASYNC* ua) { if (ctx->is_exit) { ctx->raw_sock = socket(AF_INET, SOCK_RAW, IPPROTO_ICMP); if (ctx->raw_sock == SOCKET_INVALID) - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "icmp_proxy: raw socket(SOCK_RAW) failed: %s", strerror(errno)); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "icmp_proxy: raw socket(SOCK_RAW) failed: %s", strerror(errno)); else { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy: raw socket created fd=%d", ctx->raw_sock); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy: raw socket created fd=%d", ctx->raw_sock); ctx->raw_read_id = uasync_add_socket_t(ua, ctx->raw_sock, raw_read_cb, NULL, NULL, NULL); if (!ctx->raw_read_id) { socket_close_wrapper(ctx->raw_sock); ctx->raw_sock = SOCKET_INVALID; } } @@ -348,7 +348,7 @@ int icmp_proxy_init(struct UTUN_INSTANCE* inst, struct UASYNC* ua) { etcp_router_bind(inst, ETCP_RT_ID_ICMP_PROXY, icmp_proxy_recv_cb); ctx->initialized = 1; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy initialized (exit=%d raw_sock=%d)", ctx->is_exit, (int)ctx->raw_sock); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy initialized (exit=%d raw_sock=%d)", ctx->is_exit, (int)ctx->raw_sock); return 0; } @@ -363,5 +363,5 @@ void icmp_proxy_destroy(struct UTUN_INSTANCE* inst) { struct icmp_request* r = g_icmp_ctx->pending; while (r) { struct icmp_request* n = r->next; u_free(r); r = n; } u_free(g_icmp_ctx); g_icmp_ctx = NULL; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "icmp_proxy destroyed"); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "icmp_proxy destroyed"); } diff --git a/src/proxy/socks_proxy.c b/src/proxy/socks_proxy.c index 80db5a91..4411fa21 100644 --- a/src/proxy/socks_proxy.c +++ b/src/proxy/socks_proxy.c @@ -49,20 +49,20 @@ struct listen_ctx { // ==================================================================== static int send_msg(struct UTUN_INSTANCE* inst, uint64_t group_id, uint64_t dst, uint8_t subcmd, uint32_t sid, const uint8_t* data, size_t len, int force) { struct ll_entry* e = queue_entry_new(0); - if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } + if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } e->dgram = u_malloc(TCP_PROXY_HDR_SIZE + len); - if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: malloc(%zu) failed", TCP_PROXY_HDR_SIZE + len); queue_entry_free(e); return -1; } + if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: malloc(%zu) failed", TCP_PROXY_HDR_SIZE + len); queue_entry_free(e); return -1; } e->dgram[0] = ETCP_RT_ID_TCP_PROXY; e->dgram[1] = subcmd; memcpy(e->dgram + 2, &sid, 4); if (len > 0) memcpy(e->dgram + TCP_PROXY_HDR_SIZE, data, len); if (TCP_PROXY_HDR_SIZE + len > UINT16_MAX) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: msg too large len=%zu subcmd=%02x", len, subcmd); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: msg too large len=%zu subcmd=%02x", len, subcmd); queue_dgram_free(e); queue_entry_free(e); return -1; } e->len = (uint16_t)(TCP_PROXY_HDR_SIZE + len); int ret = etcp_route_send(inst, group_id, dst, e, force); - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS send_msg subcmd=%02x sid=%08x len=%zu force=%d → ret=%d", + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS send_msg subcmd=%02x sid=%08x len=%zu force=%d → ret=%d", subcmd, sid, len, force, ret); return ret; } @@ -70,7 +70,7 @@ static int send_msg(struct UTUN_INSTANCE* inst, uint64_t group_id, uint64_t dst, static int send_connect(struct socks_proxy_conn* c) { uint8_t buf[6]; memcpy(buf, c->dest_ip, 4); memcpy(buf + 4, &c->dest_port, 2); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "SOCKS proxy: CONNECT sid=%08x to %d.%d.%d.%d:%d via_node=%016llx %s", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "SOCKS proxy: CONNECT sid=%08x to %d.%d.%d.%d:%d via_node=%016llx %s", c->stream_id, c->dest_ip[0], c->dest_ip[1], c->dest_ip[2], c->dest_ip[3], ntohs(c->dest_port), (unsigned long long)c->via_node_id, c->is_http ? "http" : "socks"); return send_msg(c->inst, TOPO_GROUP_UTUN, c->via_node_id, TCP_PROXY_SUBCMD_CONNECT, c->stream_id, buf, 6, 1); @@ -81,19 +81,19 @@ static int send_data(struct socks_proxy_conn* c, const uint8_t* data, uint16_t l } static void send_close(struct socks_proxy_conn* c) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS send CLOSE sid=%08x", c->stream_id); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS send CLOSE sid=%08x", c->stream_id); if (send_msg(c->inst, TOPO_GROUP_UTUN, c->via_node_id, TCP_PROXY_SUBCMD_CLOSE, c->stream_id, NULL, 0, 1) < 0) c->close_pending = 1; else { c->close_pending = 0; c->close_sent = 1; } } static void send_error(struct socks_proxy_conn* c) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS send ERROR sid=%08x", c->stream_id); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS send ERROR sid=%08x", c->stream_id); if (send_msg(c->inst, TOPO_GROUP_UTUN, c->via_node_id, TCP_PROXY_SUBCMD_ERROR, c->stream_id, NULL, 0, 1) < 0) c->close_pending = 1; else { c->close_pending = 0; c->close_sent = 1; } } static void send_fin(struct socks_proxy_conn* c) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS send FIN sid=%08x", c->stream_id); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS send FIN sid=%08x", c->stream_id); send_msg(c->inst, TOPO_GROUP_UTUN, c->via_node_id, TCP_PROXY_SUBCMD_FIN, c->stream_id, NULL, 0, 1); } @@ -104,12 +104,12 @@ static int write_to_client(struct socks_proxy_conn* c, const uint8_t* data, uint struct ll_entry* e = queue_entry_new_from_pool(c->tc->entry_pool); uint8_t* buf = memory_pool_alloc(c->tc->data_pool); if (!e || !buf) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: write_to_client alloc failed sid=%08x", c->stream_id); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: write_to_client alloc failed sid=%08x", c->stream_id); if (e) queue_entry_free(e); if (buf) memory_pool_free(c->tc->data_pool, buf); return -1; } if (len > c->tc->data_pool->object_size) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: write_to_client len=%u > pool_sz=%zu sid=%08x", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: write_to_client len=%u > pool_sz=%zu sid=%08x", len, c->tc->data_pool->object_size, c->stream_id); queue_entry_free(e); memory_pool_free(c->tc->data_pool, buf); return -1; @@ -128,7 +128,7 @@ static void process_socks_greeting(struct socks_proxy_conn* c) { if (c->buf_len < 3) return; uint8_t ver = c->buf[0], nmethods = c->buf[1]; if (ver != 5 || c->buf_len < (uint16_t)(2 + nmethods)) return; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "socks_proxy: greeting ver=%d nmethods=%d", ver, nmethods); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "socks_proxy: greeting ver=%d nmethods=%d", ver, nmethods); uint8_t reply[] = { 0x05, 0x00 }; write_to_client(c, reply, 2); c->buf_len = 0; @@ -138,8 +138,8 @@ static void process_socks_greeting(struct socks_proxy_conn* c) { static void process_socks_request(struct socks_proxy_conn* c) { if (c->buf_len < 10) return; uint8_t ver = c->buf[0], cmd = c->buf[1], atyp = c->buf[3]; - if (ver != 5) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad ver=%d", ver); goto error; } - if (cmd != 1) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: unsupported cmd=%d (only CONNECT supported)", cmd); goto error; } + if (ver != 5) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad ver=%d", ver); goto error; } + if (cmd != 1) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: unsupported cmd=%d (only CONNECT supported)", cmd); goto error; } uint16_t need; if (atyp == 1) need = 10; // IPv4: 4+2=6 more bytes @@ -148,7 +148,7 @@ static void process_socks_request(struct socks_proxy_conn* c) { need = (uint16_t)(5 + c->buf[4] + 2); } else if (atyp == 4) need = 22; // IPv6: 16+2=18 more - else { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: unsupported atyp=%d", atyp); goto error; } + else { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: unsupported atyp=%d", atyp); goto error; } if (c->buf_len < need) return; @@ -160,7 +160,7 @@ static void process_socks_request(struct socks_proxy_conn* c) { memcpy(c->dest_ip, c->buf + 12, 4); memcpy(&c->dest_port, c->buf + 20, 2); // TODO: proper IPv6 support - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: IPv6 unsupported, using last 4 bytes of addr"); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: IPv6 unsupported, using last 4 bytes of addr"); } else { // atyp == 3 (domain) uint8_t dlen = c->buf[4]; char domain[256]; memcpy(domain, c->buf + 5, dlen); domain[dlen] = '\0'; @@ -168,11 +168,11 @@ static void process_socks_request(struct socks_proxy_conn* c) { // resolve domain struct hostent* he = gethostbyname(domain); if (!he || he->h_addrtype != AF_INET) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: DNS failed for %s", domain); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: DNS failed for %s", domain); goto error; } memcpy(c->dest_ip, he->h_addr, 4); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: resolved %s → %d.%d.%d.%d:%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: resolved %s → %d.%d.%d.%d:%d", domain, c->dest_ip[0], c->dest_ip[1], c->dest_ip[2], c->dest_ip[3], ntohs(c->dest_port)); } @@ -181,7 +181,7 @@ static void process_socks_request(struct socks_proxy_conn* c) { uint8_t reply[] = { 0x05, 0x00, 0x00, 0x01, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 }; write_to_client(c, reply, 10); if (send_connect(c) < 0) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: send_connect failed sid=%08x", c->stream_id); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: send_connect failed sid=%08x", c->stream_id); tcp_conn_push_close(c->tc); } return; @@ -201,7 +201,7 @@ static void process_http_request(struct socks_proxy_conn* c) { if (!line_end) return; uint16_t line_len = (uint16_t)((uint8_t*)line_end - c->buf); - if (line_len < 8) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: http request too short"); goto error; } + if (line_len < 8) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: http request too short"); goto error; } char line[512]; if (line_len > sizeof(line) - 1) line_len = sizeof(line) - 1; memcpy(line, c->buf, line_len); line[line_len] = '\0'; @@ -210,23 +210,23 @@ static void process_http_request(struct socks_proxy_conn* c) { if (strncmp(line, "CONNECT ", 8) == 0) { char host_port[256]; if (sscanf(line, "CONNECT %255s HTTP/", host_port) != 1) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad http connect: %s", line); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad http connect: %s", line); goto error; } char* colon = strrchr(host_port, ':'); - if (!colon) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: no port in %s", host_port); goto error; } + if (!colon) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: no port in %s", host_port); goto error; } *colon = '\0'; int port = atoi(colon + 1); - if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad port %d", port); goto error; } + if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad port %d", port); goto error; } struct hostent* he = gethostbyname(host_port); if (!he || he->h_addrtype != AF_INET) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: DNS failed for %s", host_port); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: DNS failed for %s", host_port); uint8_t resp[] = "HTTP/1.1 502 Bad Gateway\r\n\r\n"; write_to_client(c, resp, (uint16_t)strlen((char*)resp)); tcp_conn_push_close(c->tc); return; } memcpy(c->dest_ip, he->h_addr, 4); c->dest_port = htons((uint16_t)port); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: HTTP CONNECT %s → %d.%d.%d.%d:%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: HTTP CONNECT %s → %d.%d.%d.%d:%d", host_port, c->dest_ip[0], c->dest_ip[1], c->dest_ip[2], c->dest_ip[3], port); c->buf_len = 0; @@ -245,12 +245,12 @@ static void process_http_request(struct socks_proxy_conn* c) { char method[16] = {0}, url[512] = {0}; if (sscanf(line, "%15s %511s", method, url) < 2) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad http request line: %s", line); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad http request line: %s", line); goto error; } if (strncmp(url, "http://", 7) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: not an absolute http URL: %s", url); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: not an absolute http URL: %s", url); goto error; } @@ -268,7 +268,7 @@ static void process_http_request(struct socks_proxy_conn* c) { if (hlen >= sizeof(host)) goto error; memcpy(host, host_start, hlen); host[hlen] = '\0'; port = atoi(col + 1); - if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad port %d in %s", port, url); goto error; } + if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad port %d in %s", port, url); goto error; } } else if (path_start) { size_t hlen = (size_t)(path_start - host_start); if (hlen >= sizeof(host)) goto error; @@ -279,23 +279,23 @@ static void process_http_request(struct socks_proxy_conn* c) { memcpy(host, host_start, hlen); host[hlen] = '\0'; } - if (host[0] == '\0') { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: empty host in %s", url); goto error; } + if (host[0] == '\0') { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: empty host in %s", url); goto error; } if (!path_start || *path_start == '\0') path_start = "/"; struct hostent* he = gethostbyname(host); if (!he || he->h_addrtype != AF_INET) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: DNS failed for %s", host); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: DNS failed for %s", host); uint8_t resp[] = "HTTP/1.1 502 Bad Gateway\r\n\r\n"; write_to_client(c, resp, (uint16_t)strlen((char*)resp)); tcp_conn_push_close(c->tc); return; } memcpy(c->dest_ip, he->h_addr, 4); c->dest_port = htons((uint16_t)port); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: HTTP %s %s:%d%s → %d.%d.%d.%d:%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: HTTP %s %s:%d%s → %d.%d.%d.%d:%d", method, host, port, path_start, c->dest_ip[0], c->dest_ip[1], c->dest_ip[2], c->dest_ip[3], port); if (send_connect(c) < 0) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: send_connect failed for %s", host); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: send_connect failed for %s", host); uint8_t resp[] = "HTTP/1.1 502 Bad Gateway\r\n\r\n"; write_to_client(c, resp, (uint16_t)strlen((char*)resp)); tcp_conn_push_close(c->tc); return; } @@ -314,7 +314,7 @@ static void process_http_request(struct socks_proxy_conn* c) { uint8_t hdr_buf[2048]; int hdr_n = snprintf((char*)hdr_buf, sizeof(hdr_buf), "%s %s%s\r\n", method, path_start, version_str); if (hdr_n < 0 || (size_t)hdr_n + rest_len > sizeof(hdr_buf)) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: header reconstruction overflow hdr_n=%d rest=%u", hdr_n, rest_len); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: header reconstruction overflow hdr_n=%d rest=%u", hdr_n, rest_len); goto error; } memcpy(hdr_buf + hdr_n, c->buf + rest_off, rest_len); @@ -323,7 +323,7 @@ static void process_http_request(struct socks_proxy_conn* c) { uint16_t total = hdr_chunk + extra; uint8_t* pkt = u_malloc(total); - if (!pkt) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: tx pkt malloc=%u failed sid=%08x", total, c->stream_id); goto error; } + if (!pkt) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: tx pkt malloc=%u failed sid=%08x", total, c->stream_id); goto error; } memcpy(pkt, hdr_buf, hdr_chunk); if (extra) memcpy(pkt + hdr_chunk, c->buf + headers_len, extra); @@ -362,7 +362,7 @@ static void on_read_cb(struct ll_queue* q, void* arg) { // накапливаем данные для рукопожатия uint16_t space = sizeof(c->buf) - c->buf_len; if (space < e->len) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: handshake buffer overflow sid=%08x", c->stream_id); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: handshake buffer overflow sid=%08x", c->stream_id); memory_pool_free(c->tc->data_pool, e->dgram); queue_entry_free(e); tcp_conn_push_close(c->tc); queue_resume_callback(q); return; } @@ -382,22 +382,22 @@ static void on_read_cb(struct ll_queue* q, void* arg) { // RELAY = релей данных в ETCP if (c->tx_buf) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: RELAY with pending tx_buf sid=%08x — drop new len=%u", c->stream_id, e->len); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: RELAY with pending tx_buf sid=%08x — drop new len=%u", c->stream_id, e->len); memory_pool_free(c->tc->data_pool, e->dgram); queue_entry_free(e); return; } int ret = send_data(c, e->dgram, e->len); - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS PROXY SEND sid=%08x len=%u ret=%d is_http=%d", c->stream_id, e->len, ret, c->is_http); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS PROXY SEND sid=%08x len=%u ret=%d is_http=%d", c->stream_id, e->len, ret, c->is_http); if (ret == 0) { memory_pool_free(c->tc->data_pool, e->dgram); queue_entry_free(e); queue_resume_callback(q); } else { c->tx_buf = u_malloc(e->len); if (c->tx_buf) { memcpy(c->tx_buf, e->dgram, e->len); c->tx_len = e->len; } - else { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: tx_buf malloc=%u failed sid=%08x — drop", e->len, c->stream_id); } + else { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: tx_buf malloc=%u failed sid=%08x — drop", e->len, c->stream_id); } memory_pool_free(c->tc->data_pool, e->dgram); queue_entry_free(e); etcp_router_on_send_ready(c->inst, TOPO_GROUP_UTUN, c->via_node_id, ETCP_RT_ID_TCP_PROXY, &c->tx_waiter, tx_waiter_cb, c); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCKS PROXY BP: sid=%08x tx_buf=%u waiter_reg", c->stream_id, c->tx_len); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCKS PROXY BP: sid=%08x tx_buf=%u waiter_reg", c->stream_id, c->tx_len); } } @@ -406,7 +406,7 @@ static void tx_waiter_cb(struct ll_queue* q, void* arg) { struct socks_proxy_conn* c = (struct socks_proxy_conn*)arg; if (!c->tx_buf || c->rem_closed || c->close_sent) return; int ret = send_data(c, c->tx_buf, c->tx_len); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCKS PROXY WAKE: sid=%08x tx_buf=%u ret=%d is_http=%d", c->stream_id, c->tx_len, ret, c->is_http); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCKS PROXY WAKE: sid=%08x tx_buf=%u ret=%d is_http=%d", c->stream_id, c->tx_len, ret, c->is_http); if (ret == 0) { u_free(c->tx_buf); c->tx_buf = NULL; c->tx_len = 0; queue_resume_callback(c->tc->read_queue); @@ -422,12 +422,12 @@ static void on_fin_cb(struct tcp_conn* tc, void* arg) { struct socks_proxy_conn* c = (struct socks_proxy_conn*)arg; if (c->rem_closed || c->close_sent) return; if (!tc->fin_local && !tc->write_buf && !tc->write_queue->head) { - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "socks_proxy: local FIN → relay FIN sid=%08x", c->stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "socks_proxy: local FIN → relay FIN sid=%08x", c->stream_id); send_fin(c); if (c->fin_remote && !c->close_sent && !c->close_pending) send_close(c); } else { // данные ещё в write_queue, отложим FIN - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "socks_proxy: local FIN deferred (wq=%d wbuf=%s) sid=%08x", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "socks_proxy: local FIN deferred (wq=%d wbuf=%s) sid=%08x", tc->write_queue->count, tc->write_buf ? "y" : "n", c->stream_id); tcp_conn_set_flushed(tc, NULL); } @@ -436,7 +436,7 @@ static void on_fin_cb(struct tcp_conn* tc, void* arg) { static void on_error_cb(struct tcp_conn* tc, int err, void* arg) { (void)err; struct socks_proxy_conn* c = (struct socks_proxy_conn*)arg; - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: tcp error sid=%08x err=%d state=%d fm_r=%d fm_l=%d rem_cl=%d cs=%d cp=%d " + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: tcp error sid=%08x err=%d state=%d fm_r=%d fm_l=%d rem_cl=%d cs=%d cp=%d " "bytes_client=%u bytes_exit=%u wq=%d", c->stream_id, err, c->state, tc->fin_remote, tc->fin_local, c->rem_closed, c->close_sent, c->close_pending, c->bytes_to_client, c->bytes_from_exit, c->tc->write_queue->count); @@ -446,7 +446,7 @@ static void on_error_cb(struct tcp_conn* tc, int err, void* arg) { static void on_closed_cb(struct tcp_conn* tc, void* arg) { struct socks_proxy_conn* c = (struct socks_proxy_conn*)arg; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: tcp closed sid=%08x state=%d fm_r=%d fm_l=%d rem_cl=%d bytes_client=%u bytes_exit=%u", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: tcp closed sid=%08x state=%d fm_r=%d fm_l=%d rem_cl=%d bytes_client=%u bytes_exit=%u", c->stream_id, c->state, tc->fin_remote, tc->fin_local, c->rem_closed, c->bytes_to_client, c->bytes_from_exit); if (!c->close_sent && !c->close_pending) send_close(c); socks_proxy_conn_free(c); @@ -459,11 +459,11 @@ static void on_accept_cb(socket_t sock, void* arg) { struct listen_ctx* ctx = (struct listen_ctx*)arg; struct sockaddr_in addr; socklen_t alen = sizeof(addr); socket_t csock = accept(sock, (struct sockaddr*)&addr, &alen); - if (csock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: accept failed errno=%d", errno); return; } + if (csock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: accept failed errno=%d", errno); return; } socket_set_nonblocking(csock); struct socks_proxy_conn* c = u_calloc(1, sizeof(struct socks_proxy_conn)); - if (!c) { socket_close_wrapper(csock); DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: u_calloc failed"); return; } + if (!c) { socket_close_wrapper(csock); DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: u_calloc failed"); return; } c->stream_id = ++(*ctx->next_stream_id); c->is_http = (uint8_t)ctx->is_http; c->ua = ctx->ua; c->inst = ctx->inst; c->via_node_id = ctx->via_node_id; @@ -471,7 +471,7 @@ static void on_accept_cb(socket_t sock, void* arg) { c->head = ctx->conns; c->count = ctx->conn_count; c->tc = tcp_conn_create(ctx->ua, csock, 4096, 4096, 8, 0, 0, on_fin_cb, on_error_cb, c); - if (!c->tc) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: tcp_conn_create failed"); u_free(c); socket_close_wrapper(csock); return; } + if (!c->tc) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: tcp_conn_create failed"); u_free(c); socket_close_wrapper(csock); return; } c->tc->on_closed = on_closed_cb; queue_set_callback(c->tc->read_queue, on_read_cb, c); queue_set_waiter_defer(c->tc->read_queue, 1); @@ -479,7 +479,7 @@ static void on_accept_cb(socket_t sock, void* arg) { c->next = *ctx->conns; *ctx->conns = c; (*ctx->conn_count)++; char ip[INET_ADDRSTRLEN]; inet_ntop(AF_INET, &addr.sin_addr, ip, sizeof(ip)); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: accepted %s conn from %s:%d sid=%08x total=%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: accepted %s conn from %s:%d sid=%08x total=%d", ctx->is_http ? "http" : "socks", ip, ntohs(addr.sin_port), c->stream_id, *ctx->conn_count); } @@ -499,11 +499,11 @@ int socks_proxy_handle_etcp(struct socks_proxy_conn** head, int* count, if (!c) return 0; if (subcmd == TCP_PROXY_SUBCMD_DATA) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "SOCKS DATA <- sid=%08x len=%zu", stream_id, data_len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "SOCKS DATA <- sid=%08x len=%zu", stream_id, data_len); c->bytes_from_exit += (uint32_t)data_len; if (data_len > 0) { if (data_len > c->tc->data_pool->object_size) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: data_len=%zu > pool_sz=%zu, dropping sid=%08x", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: data_len=%zu > pool_sz=%zu, dropping sid=%08x", data_len, c->tc->data_pool->object_size, stream_id); return 1; } @@ -514,7 +514,7 @@ int socks_proxy_handle_etcp(struct socks_proxy_conn** head, int* count, queue_data_put(c->tc->write_queue, e); c->bytes_to_client += (uint32_t)data_len; } else { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: handle_data alloc failed sid=%08x wq=%d bytes_in=%u bytes_out=%u", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: handle_data alloc failed sid=%08x wq=%d bytes_in=%u bytes_out=%u", stream_id, c->tc->write_queue->count, c->bytes_from_exit, c->bytes_to_client); if (e) queue_entry_free(e); if (buf) memory_pool_free(c->tc->data_pool, buf); } @@ -523,7 +523,7 @@ int socks_proxy_handle_etcp(struct socks_proxy_conn** head, int* count, } if (subcmd == TCP_PROXY_SUBCMD_CLOSE) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: REM_CLOSED sid=%08x", stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: REM_CLOSED sid=%08x", stream_id); c->rem_closed = 1; etcp_router_cancel_send_ready(c->inst, TOPO_GROUP_UTUN, c->via_node_id, ETCP_RT_ID_TCP_PROXY, &c->tx_waiter); tcp_conn_push_close(c->tc); @@ -531,7 +531,7 @@ int socks_proxy_handle_etcp(struct socks_proxy_conn** head, int* count, } if (subcmd == TCP_PROXY_SUBCMD_ERROR) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: ERROR from exit sid=%08x", stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: ERROR from exit sid=%08x", stream_id); c->rem_closed = 1; etcp_router_cancel_send_ready(c->inst, TOPO_GROUP_UTUN, c->via_node_id, ETCP_RT_ID_TCP_PROXY, &c->tx_waiter); tcp_conn_push_close(c->tc); @@ -539,7 +539,7 @@ int socks_proxy_handle_etcp(struct socks_proxy_conn** head, int* count, } if (subcmd == TCP_PROXY_SUBCMD_FIN) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: FIN from exit sid=%08x", stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: FIN from exit sid=%08x", stream_id); c->fin_remote = 1; tcp_conn_push_fin(c->tc); if (c->tc->fin_local && !c->close_sent && !c->close_pending) send_close(c); @@ -554,7 +554,7 @@ void socks_proxy_conn_free(struct socks_proxy_conn* c) { if (c->freed) return; c->freed = 1; struct socks_proxy_conn** head = c->head; int* count = c->count; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: FREE sid=%08x state=%d total=%d", c->stream_id, c->state, count ? *count : 0); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: FREE sid=%08x state=%d total=%d", c->stream_id, c->state, count ? *count : 0); if (c->close_pending && c->inst) { c->close_pending = 0; uint8_t subcmd = c->tc && c->tc->error ? TCP_PROXY_SUBCMD_ERROR : TCP_PROXY_SUBCMD_CLOSE; @@ -578,35 +578,35 @@ struct listen_ctx* socks_proxy_init_listen(struct UASYNC* ua, const char* addr_s struct socks_proxy_conn** conns, int* count, uint32_t* next_stream_id, struct UTUN_INSTANCE* inst, uint64_t via_node_id, int is_http) { char ip[64], *colon = strrchr(addr_str, ':'); - if (!colon) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad addr '%s' (need IP:PORT)", addr_str); return NULL; } + if (!colon) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad addr '%s' (need IP:PORT)", addr_str); return NULL; } size_t ip_len = (size_t)(colon - addr_str); if (ip_len > sizeof(ip) - 1) ip_len = sizeof(ip) - 1; memcpy(ip, addr_str, ip_len); ip[ip_len] = '\0'; int port = atoi(colon + 1); - if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bad port %d", port); return NULL; } + if (port <= 0 || port > 65535) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bad port %d", port); return NULL; } struct listen_ctx* ctx = u_calloc(1, sizeof(struct listen_ctx)); - if (!ctx) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: u_calloc failed"); return NULL; } + if (!ctx) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: u_calloc failed"); return NULL; } ctx->ua = ua; ctx->inst = inst; ctx->via_node_id = via_node_id; ctx->is_http = is_http; ctx->conns = conns; ctx->conn_count = count; ctx->next_stream_id = next_stream_id; socket_t sock = socket(AF_INET, SOCK_STREAM, 0); - if (sock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: socket() failed errno=%d", errno); u_free(ctx); return NULL; } + if (sock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: socket() failed errno=%d", errno); u_free(ctx); return NULL; } socket_set_nonblocking(sock); socket_set_reuseaddr(sock, 1); struct sockaddr_in addr; memset(&addr, 0, sizeof(addr)); addr.sin_family = AF_INET; addr.sin_port = htons((uint16_t)port); - if (inet_pton(AF_INET, ip, &addr.sin_addr) != 1) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: inet_pton(%s) failed", ip); socket_close_wrapper(sock); u_free(ctx); return NULL; } - if (bind(sock, (struct sockaddr*)&addr, sizeof(addr)) < 0) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: bind(%s:%d) failed errno=%d", ip, port, errno); socket_close_wrapper(sock); u_free(ctx); return NULL; } - if (listen(sock, 32) < 0) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: listen() failed errno=%d", errno); socket_close_wrapper(sock); u_free(ctx); return NULL; } + if (inet_pton(AF_INET, ip, &addr.sin_addr) != 1) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: inet_pton(%s) failed", ip); socket_close_wrapper(sock); u_free(ctx); return NULL; } + if (bind(sock, (struct sockaddr*)&addr, sizeof(addr)) < 0) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: bind(%s:%d) failed errno=%d", ip, port, errno); socket_close_wrapper(sock); u_free(ctx); return NULL; } + if (listen(sock, 32) < 0) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: listen() failed errno=%d", errno); socket_close_wrapper(sock); u_free(ctx); return NULL; } ctx->listen_sock = sock; ctx->socket_id = uasync_add_socket_t(ua, sock, on_accept_cb, NULL, NULL, ctx); - if (!ctx->socket_id) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "socks_proxy: uasync_add_socket_t failed"); socket_close_wrapper(sock); u_free(ctx); return NULL; } + if (!ctx->socket_id) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "socks_proxy: uasync_add_socket_t failed"); socket_close_wrapper(sock); u_free(ctx); return NULL; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: %s listening on %s:%d sock=%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: %s listening on %s:%d sock=%d", is_http ? "HTTP" : "SOCKS", ip, port, (int)sock); return ctx; } @@ -616,6 +616,6 @@ void socks_proxy_close_listen(struct UASYNC* ua, struct listen_ctx* ctx, socket_ if (ctx->socket_id) uasync_remove_socket_t(ua, ctx->listen_sock); socket_close_wrapper(ctx->listen_sock); if (sock_out) *sock_out = SOCKET_INVALID; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socks_proxy: listener closed sock=%d", (int)ctx->listen_sock); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "socks_proxy: listener closed sock=%d", (int)ctx->listen_sock); u_free(ctx); } diff --git a/src/proxy/tcp_proxy_client.c b/src/proxy/tcp_proxy_client.c index d04cfd84..54f147bc 100644 --- a/src/proxy/tcp_proxy_client.c +++ b/src/proxy/tcp_proxy_client.c @@ -52,11 +52,11 @@ static void tcp_proxy_client_tx_waiter_cb(struct ll_queue* q, void* arg); // ==================================================================== static struct ll_entry* tcp_proxy_client_entry_from_data(struct memory_pool* pool, const uint8_t* data, uint16_t len) { struct ll_entry* e = queue_entry_new_from_pool(pool); - if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_client_entry_from_data: pool exhausted"); return NULL; } + if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_client_entry_from_data: pool exhausted"); return NULL; } e->len = 0; e->dgram = NULL; if (len > 0) { uint8_t* buf = u_malloc(len); - if (!buf) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_client_entry_from_data: malloc(%u) failed", len); queue_entry_free(e); return NULL; } + if (!buf) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_client_entry_from_data: malloc(%u) failed", len); queue_entry_free(e); return NULL; } memcpy(buf, data, len); e->dgram = buf; e->len = len; } return e; @@ -68,9 +68,9 @@ static struct ll_entry* tcp_proxy_client_entry_from_data(struct memory_pool* poo static int tcp_proxy_client_send_msg(struct UTUN_INSTANCE* inst, uint64_t group_id, uint64_t dst, uint8_t subcmd, uint32_t sid, const uint8_t* data, size_t len, int force) { struct ll_entry* e = queue_entry_new(0); - if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } + if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } e->dgram = u_malloc(TCP_PROXY_HDR_SIZE + len); - if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "malloc(%zu) failed subcmd=%02x sid=%08x", TCP_PROXY_HDR_SIZE + len, subcmd, sid); queue_entry_free(e); return -1; } + if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "malloc(%zu) failed subcmd=%02x sid=%08x", TCP_PROXY_HDR_SIZE + len, subcmd, sid); queue_entry_free(e); return -1; } e->dgram[0] = ETCP_RT_ID_TCP_PROXY; e->dgram[1] = subcmd; memcpy(e->dgram + 2, &sid, 4); @@ -82,7 +82,7 @@ static int tcp_proxy_client_send_msg(struct UTUN_INSTANCE* inst, uint64_t group_ static int tcp_proxy_client_send_connect(struct tcp_proxy_client_conn* pc) { uint8_t buf[6]; memcpy(buf, pc->dest_ip, 4); memcpy(buf + 4, &pc->dest_port, 2); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy client: CONNECT sid=%08x to %d.%d.%d.%d:%d via node %016llx", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client: CONNECT sid=%08x to %d.%d.%d.%d:%d via node %016llx", pc->stream_id, pc->dest_ip[0], pc->dest_ip[1], pc->dest_ip[2], pc->dest_ip[3], ntohs(pc->dest_port), (unsigned long long)pc->proxy->via_node_id); return tcp_proxy_client_send_msg(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, @@ -90,13 +90,13 @@ static int tcp_proxy_client_send_connect(struct tcp_proxy_client_conn* pc) { } static int tcp_proxy_client_send_data(struct tcp_proxy_client_conn* pc, const uint8_t* data, uint16_t len) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY SEND sid=%08x len=%u", pc->stream_id, len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY SEND sid=%08x len=%u", pc->stream_id, len); return tcp_proxy_client_send_msg(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, TCP_PROXY_SUBCMD_DATA, pc->stream_id, data, len, 0); } static int tcp_proxy_client_send_close(struct tcp_proxy_client_conn* pc) { - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY SEND sid=%08x", pc->stream_id); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY SEND sid=%08x", pc->stream_id); int ret = tcp_proxy_client_send_msg(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, TCP_PROXY_SUBCMD_CLOSE, pc->stream_id, NULL, 0, 1); if (ret < 0) { pc->close_pending = 1; return -1; } @@ -115,7 +115,7 @@ static int tcp_proxy_client_send_error(struct tcp_proxy_client_conn* pc) { } static int tcp_proxy_client_send_fin(struct tcp_proxy_client_conn* pc) { - DEBUG_INFO(DEBUG_CATEGORY_TRAFFIC, "PROXY FIN RELAY sid=%08x", pc->stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY FIN RELAY sid=%08x", pc->stream_id); return tcp_proxy_client_send_msg(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, TCP_PROXY_SUBCMD_FIN, pc->stream_id, NULL, 0, 1); } @@ -135,7 +135,7 @@ static err_t tcp_proxy_client_output_cb(void *arg, struct pbuf *p, uint32_t src_ if (wr != (ssize_t)len) { uint16_t ip_total = ((uint16_t)buf[2] << 8) | buf[3]; uint32_t sip, dip; memcpy(&sip, buf + 12, 4); memcpy(&dip, buf + 16, 4); - DEBUG_ERROR(DEBUG_CATEGORY_TRAFFIC, "TUN_WRITE_ERR ret=%zd len=%u ip_total=%u", wr, len, ip_total); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TUN_WRITE_ERR ret=%zd len=%u ip_total=%u", wr, len, ip_total); } } return LERR_OK; @@ -198,7 +198,7 @@ static void tcp_proxy_client_feed_from_transport(struct tcp_proxy_client_conn *p if (sent_any) { uint32_t unsent = 0; struct tcp_seg* s; for (s = pc->pcb->unsent; s; s = s->next) unsent++; - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY FEED exit->client sid=%08x fed=%u q=%u->%u snd_wnd=%u cwnd=%u unsent=%u", + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY FEED exit->client sid=%08x fed=%u q=%u->%u snd_wnd=%u cwnd=%u unsent=%u", pc->stream_id, sent_any, q_pre, queue_entry_count(pc->to_lwip), pc->pcb->snd_wnd, pc->pcb->cwnd, unsent); tcp_output(pc->pcb); } @@ -212,7 +212,7 @@ static err_t tcp_proxy_client_accept_cb(void *arg, struct tcp_pcb *newpcb, err_t if (err != LERR_OK || !newpcb) return LERR_ABRT; struct tcp_proxy_client_conn *pc = u_calloc(1, sizeof(struct tcp_proxy_client_conn)); - if (!pc) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy client: accept alloc failed"); return LERR_MEM; } + if (!pc) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy client: accept alloc failed"); return LERR_MEM; } pc->proxy = p; pc->pcb = newpcb; pc->stream_id = ++p->next_stream_id; int i; @@ -238,10 +238,10 @@ static err_t tcp_proxy_client_accept_cb(void *arg, struct tcp_pcb *newpcb, err_t pc->to_lwip = queue_new(p->ua, 0, 0, 0, "to_lwip"); - if (tcp_proxy_client_send_connect(pc) != 0) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy client: send_connect failed sid=%08x to %d.%d.%d.%d:%d", pc->stream_id, pc->dest_ip[0], pc->dest_ip[1], pc->dest_ip[2], pc->dest_ip[3], ntohs(pc->dest_port)); tcp_arg(newpcb, NULL); tcp_abort(newpcb); queue_free(pc->to_lwip); u_free(pc); return LERR_MEM; } + if (tcp_proxy_client_send_connect(pc) != 0) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy client: send_connect failed sid=%08x to %d.%d.%d.%d:%d", pc->stream_id, pc->dest_ip[0], pc->dest_ip[1], pc->dest_ip[2], pc->dest_ip[3], ntohs(pc->dest_port)); tcp_arg(newpcb, NULL); tcp_abort(newpcb); queue_free(pc->to_lwip); u_free(pc); return LERR_MEM; } pc->next = p->conns; p->conns = pc; p->conn_count++; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy client: new conn sid=%08x local_port=%u -> %d.%d.%d.%d:%d total_conns=%d snd_wnd=%u mss=%u", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client: new conn sid=%08x local_port=%u -> %d.%d.%d.%d:%d total_conns=%d snd_wnd=%u mss=%u", pc->stream_id, newpcb->local_port, pc->dest_ip[0], pc->dest_ip[1], pc->dest_ip[2], pc->dest_ip[3], ntohs(pc->dest_port), p->conn_count, newpcb->snd_wnd, newpcb->mss); return LERR_OK; } @@ -273,7 +273,7 @@ static err_t tcp_proxy_client_recv_cb(void *arg, struct tcp_pcb *pcb, struct pbu if (p == NULL || err != LERR_OK) { pc->fin_local = 1; if (p == NULL && err == ERR_OK) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY FIN sid=%08x pcb_state=%u sndbuf=%u cwnd=%u unsent=%p unacked=%p", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY FIN sid=%08x pcb_state=%u sndbuf=%u cwnd=%u unsent=%p unacked=%p", pc->stream_id, pcb->state, pcb->snd_buf, pcb->cwnd, (void*)pcb->unsent, (void*)pcb->unacked); { uint16_t wnd_gap = TCP_WND_MAX(pcb) - pcb->rcv_wnd; @@ -284,7 +284,7 @@ static err_t tcp_proxy_client_recv_cb(void *arg, struct tcp_pcb *pcb, struct pbu tcp_proxy_client_send_close(pc); } } else { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY ERROR recv sid=%08x pcb_state=%u err=%d", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY ERROR recv sid=%08x pcb_state=%u err=%d", pc->stream_id, pcb->state, err); pc->error = 1; tcp_proxy_client_send_error(pc); @@ -302,7 +302,7 @@ static err_t tcp_proxy_client_recv_cb(void *arg, struct tcp_pcb *pcb, struct pbu uint8_t *data = u_malloc(len); if (data) { pbuf_copy_partial(p, data, len, 0); - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY RECV client->exit sid=%08x len=%u", pc->stream_id, len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY RECV client->exit sid=%08x len=%u", pc->stream_id, len); int ret = tcp_proxy_client_send_data(pc, data, len); if (ret == 0) { tcp_recved(pcb, len); u_free(data); } else { @@ -310,7 +310,7 @@ static err_t tcp_proxy_client_recv_cb(void *arg, struct tcp_pcb *pcb, struct pbu etcp_router_waiter_register(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, &pc->tx_waiter, tcp_proxy_client_tx_waiter_cb, pc); } - } else DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY recv malloc(%u) failed sid=%08x", len, pc->stream_id); + } else DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY recv malloc(%u) failed sid=%08x", len, pc->stream_id); pbuf_free(p); return LERR_OK; } @@ -325,12 +325,12 @@ static err_t tcp_proxy_client_sent_cb(void *arg, struct tcp_pcb *pcb, uint16_t l static void tcp_proxy_client_err_cb(void *arg, err_t err) { struct tcp_proxy_client_conn *pc = (struct tcp_proxy_client_conn *)arg; - if (!pc || !pc->proxy || pc->rem_closed) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY tcp_proxy_client_err_cb: pc=%p proxy=%p rem_closed=%d err=%d", (void*)pc, pc ? (void*)pc->proxy : NULL, pc ? pc->rem_closed : 0, err); return; } - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy client: error %d sid=%08x pcb_state=%u fin_local=%d rem_closed=%d", + if (!pc || !pc->proxy || pc->rem_closed) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY tcp_proxy_client_err_cb: pc=%p proxy=%p rem_closed=%d err=%d", (void*)pc, pc ? (void*)pc->proxy : NULL, pc ? pc->rem_closed : 0, err); return; } + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy client: error %d sid=%08x pcb_state=%u fin_local=%d rem_closed=%d", err, pc->stream_id, pc->pcb ? pc->pcb->state : 0, pc->fin_local, pc->rem_closed); pc->pcb = NULL;// pcb уже уничтожен стеком lwip pc->error = 1; - if (tcp_proxy_client_send_error(pc) < 0) DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY send_error failed sid=%08x", pc->stream_id); + if (tcp_proxy_client_send_error(pc) < 0) DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY send_error failed sid=%08x", pc->stream_id); } static err_t tcp_proxy_client_poll_cb(void *arg, struct tcp_pcb *pcb) { @@ -338,7 +338,7 @@ static err_t tcp_proxy_client_poll_cb(void *arg, struct tcp_pcb *pcb) { if (!pc || !pc->proxy || pc->rem_closed) return LERR_OK; if (pc->error) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY CLEANUP error sid=%08x", pc->stream_id); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY CLEANUP error sid=%08x", pc->stream_id); if (pc->pcb) { tcp_arg(pc->pcb, NULL); tcp_recv(pc->pcb, NULL); @@ -367,12 +367,12 @@ static void tcp_proxy_client_ensure_outbound_listen(struct tcp_proxy_client* p, struct tcp_pcb* lp = p->lwip->listen_pcbs; while (lp) { if (lp->local_port == dport_host) return; lp = lp->next; } struct tcp_pcb* lpcb = tcp_new(p->lwip); - if (!lpcb) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy client: tcp_new failed for dynamic listen port %u", dport_host); return; } + if (!lpcb) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy client: tcp_new failed for dynamic listen port %u", dport_host); return; } tcp_bind(lpcb, INADDR_ANY, dport_net); struct tcp_pcb* listen_pcb = tcp_listen(lpcb); if (listen_pcb) { tcp_arg(listen_pcb, p); tcp_accept(listen_pcb, tcp_proxy_client_accept_cb); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy client: dynamic listen on port %u", dport_host); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client: dynamic listen on port %u", dport_host); } } @@ -414,7 +414,7 @@ static void tcp_proxy_client_conn_free(struct tcp_proxy_client_conn *pc) { if (!pc) return; struct tcp_proxy_client *p = pc->proxy; uint32_t pending = pc->to_lwip ? queue_entry_count(pc->to_lwip) : 0; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY FREE sid=%08x total_conns=%d to_lwip_q=%u", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY FREE sid=%08x total_conns=%d to_lwip_q=%u", pc->stream_id, p->conn_count, pending); if (pc->close_pending && p && p->inst) { pc->close_pending = 0; @@ -445,11 +445,11 @@ static struct tcp_proxy_client_conn* tcp_proxy_client_find_conn(struct tcp_proxy static void tcp_proxy_client_handle_data(struct tcp_proxy_client* p, struct ETCP_CONN* conn, uint32_t stream_id, struct ll_entry* entry) { struct tcp_proxy_client_conn* pc = tcp_proxy_client_find_conn(p, stream_id); if (!pc || pc->rem_closed || pc->error) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY DATA sid=%08x — no conn/closed, dropping", stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY DATA sid=%08x — no conn/closed, dropping", stream_id); queue_dgram_free(entry); queue_entry_free(entry); return; } size_t data_len = entry->len - TCP_PROXY_HDR_SIZE; - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY DATA <- sid=%08x len=%zu", stream_id, data_len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY DATA <- sid=%08x len=%zu", stream_id, data_len); if (data_len > 0) { struct ll_entry* e = tcp_proxy_client_entry_from_data(pc->proxy->entry_pool, entry->dgram + TCP_PROXY_HDR_SIZE, (uint16_t)data_len); if (e) queue_data_put(pc->to_lwip, e); @@ -460,8 +460,8 @@ static void tcp_proxy_client_handle_data(struct tcp_proxy_client* p, struct ETCP static void tcp_proxy_client_handle_close(struct tcp_proxy_client* p, uint32_t stream_id) { struct tcp_proxy_client_conn* pc = tcp_proxy_client_find_conn(p, stream_id); - if (!pc) { DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "PROXY CLOSE sid=%08x — no conn, dropping", stream_id); return; } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY REM_CLOSED sid=%08x fin_local=%d pcb_state=%u", stream_id, pc->fin_local, pc->pcb ? pc->pcb->state : 0); + if (!pc) { DEBUG_WARN(DEBUG_CATEGORY_PROXY, "PROXY CLOSE sid=%08x — no conn, dropping", stream_id); return; } + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY REM_CLOSED sid=%08x fin_local=%d pcb_state=%u", stream_id, pc->fin_local, pc->pcb ? pc->pcb->state : 0); pc->rem_closed = 1; if (pc->tx_buf) { u_free(pc->tx_buf); pc->tx_buf = NULL; pc->tx_len = 0; } etcp_router_waiter_cancel(pc->proxy->inst, TOPO_GROUP_UTUN, pc->proxy->via_node_id, &pc->tx_waiter); @@ -479,8 +479,8 @@ static void tcp_proxy_client_handle_close(struct tcp_proxy_client* p, uint32_t s static void tcp_proxy_client_handle_error(struct tcp_proxy_client* p, uint32_t stream_id) { struct tcp_proxy_client_conn* pc = tcp_proxy_client_find_conn(p, stream_id); - if (!pc) { DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY ERROR sid=%08x — no conn, dropping", stream_id); return; } - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "PROXY ERROR from exit sid=%08x fin_local=%d", stream_id, pc->fin_local); + if (!pc) { DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY ERROR sid=%08x — no conn, dropping", stream_id); return; } + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "PROXY ERROR from exit sid=%08x fin_local=%d", stream_id, pc->fin_local); if (pc->pcb) { tcp_arg(pc->pcb, NULL); tcp_recv(pc->pcb, NULL); @@ -499,7 +499,7 @@ static void tcp_proxy_client_handle_error(struct tcp_proxy_client* p, uint32_t s static void tcp_proxy_client_handle_fin(struct tcp_proxy_client* p, uint32_t stream_id) { struct tcp_proxy_client_conn* pc = tcp_proxy_client_find_conn(p, stream_id); if (!pc || !pc->pcb) return; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY FIN FROM exit sid=%08x pcb_state=%u — shutdown write (send FIN to local)", stream_id, pc->pcb->state); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY FIN FROM exit sid=%08x pcb_state=%u — shutdown write (send FIN to local)", stream_id, pc->pcb->state); pc->fin_remote = 1; if (pc->pcb->state != TIME_WAIT && pc->pcb->state != CLOSED) { tcp_shutdown(pc->pcb, 0, 1); @@ -521,7 +521,7 @@ void tcp_proxy_client_router_recv_cb(struct ETCP_CONN* conn, struct ll_entry* en if (entry && entry->len == 9 && !conn && entry->dgram[0] == ETCP_RT_ID_TCP_PROXY) { uint64_t peer_id; memcpy(&peer_id, entry->dgram + 1, 8); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY CLOSE_ALL from %016llx — clearing client conns for peer", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY CLOSE_ALL from %016llx — clearing client conns for peer", (unsigned long long)peer_id); if (proxy) { struct tcp_proxy_client_conn *pc, *next; @@ -537,7 +537,7 @@ void tcp_proxy_client_router_recv_cb(struct ETCP_CONN* conn, struct ll_entry* en uint8_t subcmd = entry->dgram[1]; uint32_t stream_id; memcpy(&stream_id, entry->dgram + 2, 4); - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY CLIENT RECV subcmd=%02x sid=%08x pkt_len=%u", subcmd, stream_id, entry->len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY CLIENT RECV subcmd=%02x sid=%08x pkt_len=%u", subcmd, stream_id, entry->len); if (proxy) { size_t data_len = entry->len > TCP_PROXY_HDR_SIZE ? entry->len - TCP_PROXY_HDR_SIZE : 0; @@ -557,10 +557,10 @@ void tcp_proxy_client_router_recv_cb(struct ETCP_CONN* conn, struct ll_entry* en if (subcmd == TCP_PROXY_SUBCMD_FIN) { tcp_proxy_client_handle_fin(proxy, stream_id); queue_dgram_free(entry); queue_entry_free(entry); return; } } if (subcmd == TCP_PROXY_SUBCMD_DATA || subcmd == TCP_PROXY_SUBCMD_CLOSE || subcmd == TCP_PROXY_SUBCMD_FIN || subcmd == TCP_PROXY_SUBCMD_ERROR) { - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "PROXY subcmd=%02x sid=%08x — client conn not found, silent drop", subcmd, stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "PROXY subcmd=%02x sid=%08x — client conn not found, silent drop", subcmd, stream_id); queue_dgram_free(entry); queue_entry_free(entry); return; } - DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "TCP proxy client: unhandled subcmd=%02x sid=%08x", subcmd, stream_id); + DEBUG_WARN(DEBUG_CATEGORY_PROXY, "TCP proxy client: unhandled subcmd=%02x sid=%08x", subcmd, stream_id); queue_dgram_free(entry); queue_entry_free(entry); } @@ -574,15 +574,15 @@ struct tcp_proxy_client* tcp_proxy_client_create(struct UTUN_INSTANCE* inst, str int socks_enabled, const char* socks_addr, int http_proxy_enabled, const char* http_proxy_addr) { - if (!ua) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "ua is NULL"); return NULL; } + if (!ua) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "ua is NULL"); return NULL; } int need_tun = tun_name && tun_name[0] && tun_ip && tun_ip[0]; if (!need_tun && !socks_enabled && !http_proxy_enabled) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "no proxy mode enabled"); return NULL; + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "no proxy mode enabled"); return NULL; } struct tcp_proxy_client* p = u_calloc(1, sizeof(struct tcp_proxy_client)); - if (!p) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "u_calloc failed"); return NULL; } + if (!p) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "u_calloc failed"); return NULL; } p->inst = inst; p->ua = ua; p->next_stream_id = 1; p->via_node_id = via_node_id; p->mappings = mappings; p->mapping_count = mapping_count; @@ -590,15 +590,15 @@ struct tcp_proxy_client* tcp_proxy_client_create(struct UTUN_INSTANCE* inst, str p->http_proxy_enabled = http_proxy_enabled; p->entry_pool = memory_pool_init(sizeof(struct ll_entry), "entry_pool"); - if (!p->entry_pool) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "memory_pool_init failed"); u_free(p); return NULL; } + if (!p->entry_pool) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "memory_pool_init failed"); u_free(p); return NULL; } if (need_tun) { p->tun = tun_init_nat(ua, tun_name, tun_ip, mtu > 0 ? mtu : 1500, test_mode); - if (!p->tun) { DEBUG_ERROR(DEBUG_CATEGORY_TUN, "tcp_proxy_client: failed to create TUN %s", tun_name); memory_pool_destroy(p->entry_pool); u_free(p); return NULL; } + if (!p->tun) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_client: failed to create TUN %s", tun_name); memory_pool_destroy(p->entry_pool); u_free(p); return NULL; } queue_set_callback(p->tun->output_queue, tcp_proxy_client_tun_input, p); p->lwip = lwip_tcp_init(ua, tcp_proxy_client_output_cb, p); - if (!p->lwip) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "lwip_tcp_init failed"); tun_close(p->tun); memory_pool_destroy(p->entry_pool); u_free(p); return NULL; } + if (!p->lwip) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "lwip_tcp_init failed"); tun_close(p->tun); memory_pool_destroy(p->entry_pool); u_free(p); return NULL; } if (mapping_count > 0) { int j; for (j = 0; j < mapping_count; j++) { @@ -615,25 +615,25 @@ struct tcp_proxy_client* tcp_proxy_client_create(struct UTUN_INSTANCE* inst, str if (socks_enabled && socks_addr && socks_addr[0]) { p->socks_listen = socks_proxy_init_listen(ua, socks_addr, &p->socks_conns, &p->socks_conn_count, &p->next_stream_id, inst, via_node_id, 0); - if (!p->socks_listen) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_client: SOCKS init failed on %s", socks_addr); } + if (!p->socks_listen) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_client: SOCKS init failed on %s", socks_addr); } } if (http_proxy_enabled && http_proxy_addr && http_proxy_addr[0]) { p->http_listen = socks_proxy_init_listen(ua, http_proxy_addr, &p->http_conns, &p->http_conn_count, &p->next_stream_id, inst, via_node_id, 1); - if (!p->http_listen) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_client: HTTP proxy init failed on %s", http_proxy_addr); } + if (!p->http_listen) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_client: HTTP proxy init failed on %s", http_proxy_addr); } } if (inst) { if (etcp_router_bind(inst, ETCP_RT_ID_TCP_PROXY, tcp_proxy_client_router_recv_cb) != 0) { - DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "TCP proxy client: etcp_router_bind failed"); + DEBUG_WARN(DEBUG_CATEGORY_PROXY, "TCP proxy client: etcp_router_bind failed"); } else { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy client: etcp_router bind registered for ID=0x%02x", ETCP_RT_ID_TCP_PROXY); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client: etcp_router bind registered for ID=0x%02x", ETCP_RT_ID_TCP_PROXY); if (need_tun) { udp_proxy_init(inst, ua); icmp_proxy_init(inst, ua); } } } - DEBUG_INFO(DEBUG_CATEGORY_TUN, "TCP proxy client created: tun=%s socks=%s(http=%s) mappings=%d via_node=%016llx", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client created: tun=%s socks=%s(http=%s) mappings=%d via_node=%016llx", need_tun ? "yes" : "no", socks_enabled ? "yes" : "no", http_proxy_enabled ? "yes" : "no", mapping_count, (unsigned long long)via_node_id); return p; @@ -642,7 +642,7 @@ struct tcp_proxy_client* tcp_proxy_client_create(struct UTUN_INSTANCE* inst, str void tcp_proxy_client_destroy(struct tcp_proxy_client* p) { if (!p) return; int total = p->conn_count + p->socks_conn_count + p->http_conn_count; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy client destroying: lwip=%d socks=%d http=%d", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy client destroying: lwip=%d socks=%d http=%d", p->conn_count, p->socks_conn_count, p->http_conn_count); if (p->inst) etcp_router_unbind(p->inst, ETCP_RT_ID_TCP_PROXY); udp_proxy_destroy(p->inst); diff --git a/src/proxy/tcp_proxy_server.c b/src/proxy/tcp_proxy_server.c index 5668915c..657aead1 100644 --- a/src/proxy/tcp_proxy_server.c +++ b/src/proxy/tcp_proxy_server.c @@ -52,15 +52,15 @@ static inline int write_pending(struct tcp_conn* tc) { static int send_msg(struct UTUN_INSTANCE* inst, uint64_t group_id, uint64_t dst, uint8_t subcmd, uint32_t sid, const uint8_t* data, size_t len, int force) { struct ll_entry* e = queue_entry_new(0); - if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_server: queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } + if (!e) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_server: queue_entry_new failed subcmd=%02x sid=%08x", subcmd, sid); return -1; } e->dgram = u_malloc(TCP_PROXY_HDR_SIZE + len); - if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_server: malloc(%zu) failed", TCP_PROXY_HDR_SIZE + len); queue_entry_free(e); return -1; } + if (!e->dgram) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_server: malloc(%zu) failed", TCP_PROXY_HDR_SIZE + len); queue_entry_free(e); return -1; } e->dgram[0] = ETCP_RT_ID_TCP_PROXY; e->dgram[1] = subcmd; memcpy(e->dgram + 2, &sid, 4); if (len > 0) memcpy(e->dgram + TCP_PROXY_HDR_SIZE, data, len); if (TCP_PROXY_HDR_SIZE + len > UINT16_MAX) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_server: msg too large len=%zu subcmd=%02x", len, subcmd); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_server: msg too large len=%zu subcmd=%02x", len, subcmd); queue_dgram_free(e); queue_entry_free(e); return -1; } e->len = TCP_PROXY_HDR_SIZE + len; @@ -120,7 +120,7 @@ static void on_fin_cb(struct tcp_conn* tc, void* arg) { if (rc->cli_closed) return; int pend_w = write_pending(tc); int pend_r = (rc->tx_buf != NULL) || (tc->read_queue && tc->read_queue->head); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "SOCK:DST_FIN fd=%d sid=%08x fin_l=%d pend_w=%d pend_r=%d " "sent=%u recv=%u relayed=%u drain#=%u data#=%u " "rq=%d(%zub) wq=%d(%zub) wbuf=%s err=%d tx_buf=%s", @@ -145,7 +145,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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FLUSHED fd=%d sid=%08x fin_local=%d — both FINs, closing", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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; } @@ -154,7 +154,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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSED fd=%d sid=%08x — freeing", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCK:CLOSED fd=%d sid=%08x — freeing", tc ? (int)tc->sock : -1, rc->stream_id); tcp_proxy_server_conn_free(rc); } @@ -163,7 +163,7 @@ static void on_error_cb(struct tcp_conn* tc, int err, void* arg) { (void)err; if (tc->closed) return; struct tcp_proxy_server_conn* rc = (struct tcp_proxy_server_conn*)arg; - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "SOCK:ERR fd=%d sid=%08x err=%d fin_r=%d fin_l=%d " "sent=%u recv=%u relayed=%u drain#=%u data#=%u " "rq=%d wq=%d wbuf=%s conn=%d", @@ -191,7 +191,7 @@ static void diag_timer_cb(void* arg) { getsockopt(tc->sock, SOL_SOCKET, SO_RCVBUF, (char*)&rcv_buf, &optlen); getsockopt(tc->sock, SOL_SOCKET, SO_SNDBUF, (char*)&snd_buf, &optlen); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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", @@ -216,7 +216,7 @@ static void read_queue_drain_cb(struct ll_queue* q, void* arg) { if (rc->tx_buf) { int ret = send_msg(inst, TOPO_GROUP_UTUN, rc->peer_node_id, TCP_PROXY_SUBCMD_DATA, rc->stream_id, rc->tx_buf, rc->tx_len, 0); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "TPS TXBUF RETRY: sid=%08x len=%u ret=%d", rc->stream_id, rc->tx_len, ret); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "TPS TXBUF RETRY: sid=%08x len=%u ret=%d", rc->stream_id, rc->tx_len, ret); if (ret == 0) { u_free(rc->tx_buf); rc->tx_buf = NULL; rc->tx_len = 0; if (rc->retry_timer) { uasync_cancel_timeout(rc->ua, rc->retry_timer); rc->retry_timer = NULL; } @@ -229,7 +229,7 @@ static void read_queue_drain_cb(struct ll_queue* q, void* arg) { etcp_router_on_send_ready(inst, TOPO_GROUP_UTUN, rc->peer_node_id, ETCP_RT_ID_TCP_PROXY, &rc->pause_waiter, pause_resume_cb, rc); if (!rc->retry_timer) rc->retry_timer = uasync_set_timeout(rc->ua, 5000, rc, retry_timer_cb, "tps_retry"); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "TPS TXBUF BP AGAIN: sid=%08x waiter_reg", rc->stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "TPS TXBUF BP AGAIN: sid=%08x waiter_reg", rc->stream_id); return; } } @@ -253,7 +253,7 @@ static void read_queue_drain_cb(struct ll_queue* q, void* arg) { } int ret = send_msg(inst, TOPO_GROUP_UTUN, rc->peer_node_id, TCP_PROXY_SUBCMD_DATA, rc->stream_id, e->dgram, e->len, 0); rc->bytes_relayed += e->len; rc->drain_count++; - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "TPS DRAIN #%u sid=%08x len=%u → ret=%d rq=%d", + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "TPS DRAIN #%u sid=%08x len=%u → ret=%d rq=%d", rc->drain_count, rc->stream_id, e->len, ret, q->count); if (ret == 0) { memory_pool_free(rc->tc->data_pool, e->dgram); queue_entry_free(e); @@ -261,9 +261,9 @@ static void read_queue_drain_cb(struct ll_queue* q, void* arg) { } else { rc->tx_buf = u_malloc(e->len); if (rc->tx_buf) { memcpy(rc->tx_buf, e->dgram, e->len); rc->tx_len = e->len; } - else { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TPS tx_buf malloc=%u failed sid=%08x — drop", e->len, rc->stream_id); } + else { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TPS tx_buf malloc=%u failed sid=%08x — drop", e->len, rc->stream_id); } memory_pool_free(rc->tc->data_pool, e->dgram); queue_entry_free(e); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:BACKPRESSURE fd=%d sid=%08x — buffered %u for retry", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCK:BACKPRESSURE fd=%d sid=%08x — buffered %u for retry", (int)rc->tc->sock, rc->stream_id, rc->tx_len); etcp_router_on_send_ready(inst, TOPO_GROUP_UTUN, rc->peer_node_id, ETCP_RT_ID_TCP_PROXY, &rc->pause_waiter, pause_resume_cb, rc); @@ -275,7 +275,7 @@ static void pause_resume_cb(struct ll_queue* q, void* arg) { (void)q; struct tcp_proxy_server_conn* rc = (struct tcp_proxy_server_conn*)arg; if (!rc->tc || rc->tc->sock == SOCKET_INVALID || rc->cli_closed) return; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "TPS RESUME sid=%08x tx_buf=%s rq=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "TPS RESUME sid=%08x tx_buf=%s rq=%d", rc->stream_id, rc->tx_buf ? "y" : "n", rc->tc->read_queue ? rc->tc->read_queue->count : 0); queue_resume_callback(rc->tc->read_queue); @@ -287,7 +287,7 @@ static void retry_timer_cb(void* arg) { if (!rc->tx_buf || !rc->tc || rc->tc->sock == SOCKET_INVALID || rc->cli_closed) return; struct UTUN_INSTANCE* inst = rc->ctx ? rc->ctx->inst : NULL; int ret = send_msg(inst, TOPO_GROUP_UTUN, rc->peer_node_id, TCP_PROXY_SUBCMD_DATA, rc->stream_id, rc->tx_buf, rc->tx_len, 1); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "TPS RETRY TIMER: sid=%08x len=%u force=1 ret=%d", rc->stream_id, rc->tx_len, ret); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "TPS RETRY TIMER: sid=%08x len=%u force=1 ret=%d", rc->stream_id, rc->tx_len, ret); if (ret == 0) { u_free(rc->tx_buf); rc->tx_buf = NULL; rc->tx_len = 0; if (rc->dst_fin_deferred && rc->tc->read_queue && !rc->tc->read_queue->head) { @@ -314,14 +314,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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE enter rc=%p freed=%d sid=%08x", (void*)rc, rc->freed, rc->stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "SOCK:FREE double rc=%p — IGNORED", (void*)rc); return; } rc->freed = 1; int total = conn_total(rc); - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE fd=%d sid=%08x total=%d cli_closed=%d fin=%d error=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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; @@ -338,7 +338,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->tc) { tcp_conn_destroy(rc->tc); rc->tc = NULL; } - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FREE u_free rc=%p", (void*)rc); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCK:FREE u_free rc=%p", (void*)rc); u_free(rc); } @@ -355,25 +355,25 @@ struct tcp_proxy_server_conn* tcp_proxy_server_find_conn(struct tcp_proxy_server int tcp_proxy_server_handle_connect(struct UTUN_INSTANCE* inst, struct ll_entry* entry, uint32_t stream_id, uint64_t src_node_id) { if (!inst || !inst->tcp_proxy_server.enabled) { if (entry) { queue_dgram_free(entry); queue_entry_free(entry); } return -1; } struct tcp_proxy_server* ctx = &inst->tcp_proxy_server; - if (entry->len < TCP_PROXY_CONNECT_HDR_SIZE) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy server: CONNECT too short len=%u", entry->len); queue_dgram_free(entry); queue_entry_free(entry); return -1; } + if (entry->len < TCP_PROXY_CONNECT_HDR_SIZE) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy server: CONNECT too short len=%u", entry->len); queue_dgram_free(entry); queue_entry_free(entry); return -1; } uint8_t* dest_ip = entry->dgram + TCP_PROXY_HDR_SIZE; uint16_t dest_port = 0; memcpy(&dest_port, dest_ip + 4, 2); struct tcp_proxy_server_conn* rc = u_calloc(1, sizeof(struct tcp_proxy_server_conn)); - if (!rc) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy server: u_calloc failed sid=%08x", stream_id); queue_dgram_free(entry); queue_entry_free(entry); return -1; } + if (!rc) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy server: u_calloc failed sid=%08x", stream_id); queue_dgram_free(entry); queue_entry_free(entry); return -1; } rc->ctx = ctx; rc->stream_id = stream_id; rc->peer_node_id = src_node_id; memcpy(rc->dest_ip, dest_ip, 4); rc->dest_port = dest_port; rc->ua = inst->ua; 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; } + if (sock == SOCKET_INVALID) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "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_INFO(DEBUG_CATEGORY_PROXY, "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); rc->tc = tcp_conn_create(inst->ua, sock, 1500, 8192, 4, 0, inst->config->global.tcp_recv_buf, on_fin_cb, on_error_cb, rc); - if (!rc->tc) { DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy server: tcp_conn_create failed"); socket_close_wrapper(sock); ctx->conn_count--; u_free(rc); queue_dgram_free(entry); queue_entry_free(entry); return -1; } + if (!rc->tc) { DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy server: tcp_conn_create failed"); socket_close_wrapper(sock); ctx->conn_count--; u_free(rc); queue_dgram_free(entry); queue_entry_free(entry); return -1; } rc->tc->on_closed = on_closed_cb; queue_set_callback(rc->tc->read_queue, read_queue_drain_cb, rc); queue_set_waiter_defer(rc->tc->read_queue, 1); @@ -382,7 +382,7 @@ int tcp_proxy_server_handle_connect(struct UTUN_INSTANCE* inst, struct ll_entry* addr.sin_family = AF_INET; memcpy(&addr.sin_addr.s_addr, dest_ip, 4); addr.sin_port = dest_port; int ret = connect(sock, (struct sockaddr*)&addr, sizeof(addr)); if (ret < 0 && errno != EINPROGRESS) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "TCP proxy server: connect() to %d.%d.%d.%d:%d failed: %s", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "TCP proxy server: connect() to %d.%d.%d.%d:%d failed: %s", dest_ip[0], dest_ip[1], dest_ip[2], dest_ip[3], ntohs(dest_port), strerror(errno)); send_msg(inst, TOPO_GROUP_UTUN, src_node_id, TCP_PROXY_SUBCMD_ERROR, stream_id, NULL, 0, 1); ctx->conn_count--; tcp_conn_destroy(rc->tc); u_free(rc); @@ -402,16 +402,16 @@ int tcp_proxy_server_handle_data(struct UTUN_INSTANCE* inst, struct ETCP_CONN* c 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->sock == SOCKET_INVALID || rc->tc->error || rc->cli_closed) { - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TPS handle_data: no/closed conn sid=%08x, dropping", stream_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TPS handle_data: no/closed conn sid=%08x, dropping", stream_id); queue_dgram_free(entry); queue_entry_free(entry); return -1; } size_t data_len = entry->len - TCP_PROXY_HDR_SIZE; rc->bytes_sent += (uint32_t)data_len; rc->data_count++; - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "TPS DATA #%u sid=%08x len=%zu", + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "TPS DATA #%u sid=%08x len=%zu", rc->data_count, stream_id, data_len); if (data_len > 0) { if (data_len > rc->tc->data_pool->object_size) { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_server: data_len=%zu > pool_sz=%zu, dropping sid=%08x", + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_server: data_len=%zu > pool_sz=%zu, dropping sid=%08x", data_len, rc->tc->data_pool->object_size, stream_id); queue_dgram_free(entry); queue_entry_free(entry); return -1; } @@ -422,7 +422,7 @@ int tcp_proxy_server_handle_data(struct UTUN_INSTANCE* inst, struct ETCP_CONN* c e->dgram = buf; e->len = (uint16_t)data_len; queue_data_put(rc->tc->write_queue, e); } else { - DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "tcp_proxy_server: handle_data alloc failed sid=%08x", stream_id); + DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "tcp_proxy_server: handle_data alloc failed sid=%08x", stream_id); if (e) queue_entry_free(e); if (buf) memory_pool_free(rc->tc->data_pool, buf); } @@ -435,8 +435,8 @@ void tcp_proxy_server_handle_close(struct UTUN_INSTANCE* inst, uint32_t stream_i if (!inst) return; 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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:CLOSE_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", + if (!rc) { DEBUG_WARN(DEBUG_CATEGORY_PROXY, "TCP proxy server: CLOSE sid=%08x — no conn", stream_id); return; } + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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; @@ -457,8 +457,8 @@ void tcp_proxy_server_handle_error(struct UTUN_INSTANCE* inst, uint32_t stream_i if (!inst) return; 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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:ERROR_RECV fd=%d sid=%08x total=%d fin=%d write_pend=%d", + if (!rc) { DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy server: ERROR sid=%08x — no conn", stream_id); return; } + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "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); @@ -469,7 +469,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_DEBUG(DEBUG_CATEGORY_SOCKET, "SOCK:FIN_RECV fd=%d sid=%08x — pushing FIN to wq", + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "SOCK:FIN_RECV fd=%d sid=%08x — pushing FIN to wq", (int)rc->tc->sock, stream_id); tcp_conn_push_fin(rc->tc); } @@ -484,7 +484,7 @@ void tcp_proxy_server_recv_cb(struct ETCP_CONN* conn, struct ll_entry* entry) { if (entry && entry->len == 9 && !conn && entry->dgram[0] == ETCP_RT_ID_TCP_PROXY) { uint64_t peer_id; memcpy(&peer_id, entry->dgram + 1, 8); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "PROXY CLOSE_ALL from %016llx — clearing server conns for peer", + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "PROXY CLOSE_ALL from %016llx — clearing server conns for peer", (unsigned long long)peer_id); if (inst && inst->tcp_proxy_server.enabled) { struct tcp_proxy_server_conn *rc, *next; @@ -500,7 +500,7 @@ void tcp_proxy_server_recv_cb(struct ETCP_CONN* conn, struct ll_entry* entry) { uint8_t subcmd = entry->dgram[1]; uint32_t stream_id; memcpy(&stream_id, entry->dgram + 2, 4); - DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "PROXY SERVER RECV subcmd=%02x sid=%08x pkt_len=%u", subcmd, stream_id, entry->len); + DEBUG_TRACE(DEBUG_CATEGORY_PROXY, "PROXY SERVER RECV subcmd=%02x sid=%08x pkt_len=%u", subcmd, stream_id, entry->len); if (subcmd == TCP_PROXY_SUBCMD_CONNECT) { uint64_t src_node_id = conn ? conn->peer_node_id : (inst ? inst->node_id : 0); @@ -517,10 +517,10 @@ void tcp_proxy_server_recv_cb(struct ETCP_CONN* conn, struct ll_entry* entry) { } } if (subcmd == TCP_PROXY_SUBCMD_DATA || subcmd == TCP_PROXY_SUBCMD_CLOSE || subcmd == TCP_PROXY_SUBCMD_FIN || subcmd == TCP_PROXY_SUBCMD_ERROR) { - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "PROXY subcmd=%02x sid=%08x — server conn not found, silent drop", subcmd, stream_id); + DEBUG_DEBUG(DEBUG_CATEGORY_PROXY, "PROXY subcmd=%02x sid=%08x — server conn not found, silent drop", subcmd, stream_id); queue_dgram_free(entry); queue_entry_free(entry); return; } - DEBUG_WARN(DEBUG_CATEGORY_SOCKET, "TCP proxy server: unhandled subcmd=%02x sid=%08x", subcmd, stream_id); + DEBUG_WARN(DEBUG_CATEGORY_PROXY, "TCP proxy server: unhandled subcmd=%02x sid=%08x", subcmd, stream_id); queue_dgram_free(entry); queue_entry_free(entry); } @@ -542,19 +542,19 @@ int tcp_proxy_server_init(struct UTUN_INSTANCE* inst) { udp_proxy_init(inst, inst->ua); icmp_proxy_init(inst, inst->ua); } - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy server initialized node=%016llx", (unsigned long long)inst->node_id); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy server initialized node=%016llx", (unsigned long long)inst->node_id); return 0; } void tcp_proxy_server_destroy(struct UTUN_INSTANCE* inst) { if (!inst) return; struct tcp_proxy_server* ctx = &inst->tcp_proxy_server; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy server destroying: conn_count=%d", ctx->conn_count); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy server destroying: conn_count=%d", ctx->conn_count); struct tcp_proxy_server_conn* rc = ctx->conns; while (rc) { struct tcp_proxy_server_conn* next = rc->next; tcp_proxy_server_conn_free(rc); rc = next; } ctx->conns = NULL; ctx->enabled = 0; if (g_tcp_proxy_server_ctx == ctx) g_tcp_proxy_server_ctx = NULL; udp_proxy_destroy(inst); icmp_proxy_destroy(inst); - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "TCP proxy server destroyed"); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "TCP proxy server destroyed"); } diff --git a/src/proxy/udp_proxy.c b/src/proxy/udp_proxy.c index 911c0336..25887046 100644 --- a/src/proxy/udp_proxy.c +++ b/src/proxy/udp_proxy.c @@ -92,7 +92,7 @@ static void exit_handle_data(struct ETCP_CONN* conn, struct ll_entry* entry) { f->ua = g_udp_ctx->ua; f->created_tb = get_time_tb(); f->last_activity_tb = f->created_tb; f->sock = socket(AF_INET, SOCK_DGRAM, 0); - if (f->sock == SOCKET_INVALID) { u_free(f); DEBUG_ERROR(DEBUG_CATEGORY_SOCKET, "udp_proxy: socket failed"); goto drop; } + if (f->sock == SOCKET_INVALID) { u_free(f); DEBUG_ERROR(DEBUG_CATEGORY_PROXY, "udp_proxy: socket failed"); goto drop; } socket_set_nonblocking(f->sock); struct sockaddr_in bind_addr = {.sin_family = AF_INET, .sin_addr = {.s_addr = INADDR_ANY}, .sin_port = 0}; bind(f->sock, (struct sockaddr*)&bind_addr, sizeof(bind_addr)); @@ -248,7 +248,7 @@ int udp_proxy_init(struct UTUN_INSTANCE* inst, struct UASYNC* ua) { etcp_router_bind(inst, ETCP_RT_ID_UDP_PROXY, udp_proxy_recv_cb); ctx->initialized = 1; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "udp_proxy initialized (exit=%d)", ctx->is_exit); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "udp_proxy initialized (exit=%d)", ctx->is_exit); return 0; } @@ -261,5 +261,5 @@ void udp_proxy_destroy(struct UTUN_INSTANCE* inst) { if (f->read_id) { uasync_remove_socket_t(g_udp_ctx->ua, f->sock); f->read_id = NULL; } socket_close_wrapper(f->sock); u_free(f); f = n; } u_free(g_udp_ctx); g_udp_ctx = NULL; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "udp_proxy destroyed"); + DEBUG_INFO(DEBUG_CATEGORY_PROXY, "udp_proxy destroyed"); }