debug: 增加终端日志测试连通性

c/cmd/kcppeer.c

@@ -69,6 +69,7 @@ int main(int argc, char **argv) {
     const char *peer_id = "peer-a";
     const char *server_addr = "127.0.0.1:9002";
     const char *relay_via = "";
+    const char *actual_dial_target;
     const char *target_peer = "";
     const char *text = "";
     const char *file_path = "";
@@ -238,15 +239,20 @@ int main(int argc, char **argv) {
         }
     }
 
+    actual_dial_target = relay_via[0] != '\0' ? relay_via : server_addr;
     client = kcp_client_dial(server_addr, relay_via, peer_id, bind_ip, bind_device, latency_logger, packet_logger, stats_logger, stats_interval_ms);
     if (client == NULL) {
-        fprintf(stderr, "kcppeer: dial kcp server %s failed\n", server_addr);
+        if (relay_via[0] != '\0') {
+            fprintf(stderr, "kcppeer: dial target %s failed (logical server %s)\n", actual_dial_target, server_addr);
+        } else {
+            fprintf(stderr, "kcppeer: dial kcp server %s failed\n", server_addr);
+        }
         goto cleanup;
     }
     if (relay_via[0] != '\0') {
-        fprintf(stderr, "opened KCP session as %s; logical server=%s, actual dial target=%s via relay; register not yet confirmed\n", kcp_client_id(client), server_addr, relay_via);
+        fprintf(stderr, "opened KCP session as %s; logical server=%s, actual dial target=%s via relay; register not yet confirmed\n", kcp_client_id(client), server_addr, actual_dial_target);
     } else {
-        fprintf(stderr, "opened KCP session as %s; logical server=%s, actual dial target=%s; register not yet confirmed\n", kcp_client_id(client), server_addr, server_addr);
+        fprintf(stderr, "opened KCP session as %s; logical server=%s, actual dial target=%s; register not yet confirmed\n", kcp_client_id(client), server_addr, actual_dial_target);
     }
 
     receive_ctx.client = client;

c/src/server_udp_relay.c

@@ -10,10 +10,13 @@ struct udp_relay {
     int upstream_fd;
     struct sockaddr_storage upstream_addr;
     socklen_t upstream_addr_len;
+    char downstream_local_addr[OMNI_MAX_ADDR_TEXT];
+    char upstream_local_addr[OMNI_MAX_ADDR_TEXT];
     struct sockaddr_storage client_addr;
     socklen_t client_addr_len;
     int has_client;
     pthread_mutex_t lock;
+    pthread_mutex_t log_mu;
     pthread_mutex_t state_mu;
     pthread_cond_t state_cond;
     pthread_t downstream_thread;
@@ -26,6 +29,88 @@ struct udp_relay {
     int closed;
 };
 
+static void udp_relay_parse_kcp_summary(const uint8_t *packet, size_t len, int *has_conv, uint32_t *conv, size_t *segment_count) {
+    size_t offset = 0;
+    size_t count = 0;
+
+    if (has_conv != NULL) {
+        *has_conv = 0;
+    }
+    if (conv != NULL) {
+        *conv = 0;
+    }
+    if (segment_count != NULL) {
+        *segment_count = 0;
+    }
+    if (packet == NULL || len < 4U) {
+        return;
+    }
+    if (has_conv != NULL) {
+        *has_conv = 1;
+    }
+    if (conv != NULL) {
+        *conv = (uint32_t) ((unsigned char) packet[0] |
+                            ((unsigned char) packet[1] << 8) |
+                            ((unsigned char) packet[2] << 16) |
+                            ((unsigned char) packet[3] << 24));
+    }
+    while (offset + 24U <= len) {
+        uint32_t seg_len = (uint32_t) ((unsigned char) packet[offset + 20] |
+                                       ((unsigned char) packet[offset + 21] << 8) |
+                                       ((unsigned char) packet[offset + 22] << 16) |
+                                       ((unsigned char) packet[offset + 23] << 24));
+        if (offset + 24U + seg_len > len) {
+            return;
+        }
+        count++;
+        offset += 24U + seg_len;
+    }
+    if (segment_count != NULL) {
+        *segment_count = count;
+    }
+}
+
+static void udp_relay_print_packet(udp_relay_t *relay, const char *event_name, const char *local_addr, const struct sockaddr_storage *remote_addr, socklen_t remote_addr_len, const uint8_t *packet, size_t packet_len) {
+    char remote_addr_text[OMNI_MAX_ADDR_TEXT];
+    int64_t ts_unix_nano;
+    int has_conv = 0;
+    uint32_t conv = 0;
+    size_t segment_count = 0;
+
+    if (relay == NULL) {
+        return;
+    }
+
+    if (remote_addr != NULL && remote_addr_len > 0) {
+        omni_sockaddr_to_string((const struct sockaddr *) remote_addr, remote_addr_len, remote_addr_text, sizeof(remote_addr_text));
+    } else {
+        remote_addr_text[0] = '\0';
+    }
+    ts_unix_nano = omni_now_unix_nano();
+    udp_relay_parse_kcp_summary(packet, packet_len, &has_conv, &conv, &segment_count);
+
+    pthread_mutex_lock(&relay->log_mu);
+    if (has_conv) {
+        fprintf(stderr, "[relay] ts=%" PRId64 " event=%s local=%s remote=%s bytes=%zu conv=%" PRIu32 " segs=%zu\n",
+                ts_unix_nano,
+                event_name == NULL ? "" : event_name,
+                local_addr == NULL ? "" : local_addr,
+                remote_addr_text,
+                packet_len,
+                conv,
+                segment_count);
+    } else {
+        fprintf(stderr, "[relay] ts=%" PRId64 " event=%s local=%s remote=%s bytes=%zu\n",
+                ts_unix_nano,
+                event_name == NULL ? "" : event_name,
+                local_addr == NULL ? "" : local_addr,
+                remote_addr_text,
+                packet_len);
+    }
+    fflush(stderr);
+    pthread_mutex_unlock(&relay->log_mu);
+}
+
 static int udp_relay_is_closed(udp_relay_t *relay) {
     int closed;
 
@@ -90,8 +175,10 @@ static void *udp_relay_forward_downstream_to_upstream(void *arg) {
         }
 
         udp_relay_record_client(relay, &source, source_len);
+        udp_relay_print_packet(relay, "relay_downstream_rx", relay->downstream_local_addr, &source, source_len, buffer, (size_t) n);
         for (;;) {
             if (send(relay->upstream_fd, buffer, (size_t) n, 0) >= 0) {
+                udp_relay_print_packet(relay, "relay_upstream_tx", relay->upstream_local_addr, &relay->upstream_addr, relay->upstream_addr_len, buffer, (size_t) n);
                 break;
             }
             {
@@ -132,12 +219,15 @@ static void *udp_relay_forward_upstream_to_downstream(void *arg) {
             return NULL;
         }
 
+        udp_relay_print_packet(relay, "relay_upstream_rx", relay->upstream_local_addr, &relay->upstream_addr, relay->upstream_addr_len, buffer, (size_t) n);
         if (!udp_relay_copy_client(relay, &client_addr, &client_addr_len)) {
+            udp_relay_print_packet(relay, "relay_upstream_drop_no_client", relay->upstream_local_addr, &relay->upstream_addr, relay->upstream_addr_len, buffer, (size_t) n);
             continue;
         }
 
         for (;;) {
             if (sendto(relay->downstream_fd, buffer, (size_t) n, 0, (struct sockaddr *) &client_addr, client_addr_len) >= 0) {
+                udp_relay_print_packet(relay, "relay_downstream_tx", relay->downstream_local_addr, &client_addr, client_addr_len, buffer, (size_t) n);
                 break;
             }
             {
@@ -170,8 +260,12 @@ static void udp_relay_join_threads(udp_relay_t *relay) {
 udp_relay_t *udp_relay_open(const char *listen_addr, const char *upstream_addr) {
     struct sockaddr_storage listen_ss;
     struct sockaddr_storage upstream_ss;
+    struct sockaddr_storage downstream_local_ss;
+    struct sockaddr_storage upstream_local_ss;
     socklen_t listen_len;
     socklen_t upstream_len;
+    socklen_t downstream_local_len = sizeof(downstream_local_ss);
+    socklen_t upstream_local_len = sizeof(upstream_local_ss);
     int family;
     int fd_listen = -1;
     int fd_upstream = -1;
@@ -209,7 +303,18 @@ udp_relay_t *udp_relay_open(const char *listen_addr, const char *upstream_addr)
     relay->upstream_fd = fd_upstream;
     memcpy(&relay->upstream_addr, &upstream_ss, sizeof(upstream_ss));
     relay->upstream_addr_len = upstream_len;
+    if (getsockname(fd_listen, (struct sockaddr *) &downstream_local_ss, &downstream_local_len) == 0) {
+        omni_sockaddr_to_string((const struct sockaddr *) &downstream_local_ss, downstream_local_len, relay->downstream_local_addr, sizeof(relay->downstream_local_addr));
+    } else {
+        snprintf(relay->downstream_local_addr, sizeof(relay->downstream_local_addr), "%s", listen_addr == NULL ? "" : listen_addr);
+    }
+    if (getsockname(fd_upstream, (struct sockaddr *) &upstream_local_ss, &upstream_local_len) == 0) {
+        omni_sockaddr_to_string((const struct sockaddr *) &upstream_local_ss, upstream_local_len, relay->upstream_local_addr, sizeof(relay->upstream_local_addr));
+    } else {
+        snprintf(relay->upstream_local_addr, sizeof(relay->upstream_local_addr), "%s", listen_addr == NULL ? "" : listen_addr);
+    }
     pthread_mutex_init(&relay->lock, NULL);
+    pthread_mutex_init(&relay->log_mu, NULL);
     pthread_mutex_init(&relay->state_mu, NULL);
     pthread_cond_init(&relay->state_cond, NULL);
     return relay;
@@ -305,6 +410,7 @@ void udp_relay_free(udp_relay_t *relay) {
     udp_relay_close(relay);
     udp_relay_join_threads(relay);
     pthread_mutex_destroy(&relay->lock);
+    pthread_mutex_destroy(&relay->log_mu);
     pthread_cond_destroy(&relay->state_cond);
     pthread_mutex_destroy(&relay->state_mu);
     free(relay);