event: log packet before encryption

Signed-off-by: He Xian <hexian000@outlook.com>
hexian000 · Jan 20, 2024 · 5d9365f · 5d9365f
1 parent 819d122
commit 5d9365f
Show file tree

Hide file tree

Showing 3 changed files with 28 additions and 12 deletions.
diff --git a/src/event_pkt.c b/src/event_pkt.c
@@ -18,19 +18,15 @@
 #include <stddef.h>
 #include <string.h>
 
-#define MSG_LOGV(what, msg)                                                    \
+#define PKT_LOGV(what, msg)                                                    \
 	do {                                                                   \
 		if (!LOGLEVEL(VERBOSE)) {                                      \
 			break;                                                 \
 		}                                                              \
 		char addr[64];                                                 \
 		format_sa(&(msg)->addr.sa, addr, sizeof(addr));                \
-		LOG_F(VERBOSE, what ": %" PRIu16 " bytes to %s", (msg)->len,   \
-		      addr);                                                   \
-		FILE *log_fp = slog_file;                                      \
-		if (log_fp != NULL) {                                          \
-			print_bin(log_fp, "  ", (msg)->buf, (msg)->len);       \
-		}                                                              \
+		LOG_F(VERBOSE, what ": %" PRIu16 " bytes, addr=%s",            \
+		      (msg)->len, addr);                                       \
 	} while (0)
 
 static void udp_reset(struct server *restrict s)
@@ -127,7 +123,7 @@ static size_t pkt_recv(struct server *restrict s, const int fd)
 			msg->len = (size_t)mmsgs[i].msg_len;
 			msg->ts = now;
 			q->mq_recv[q->mq_recv_len++] = msg;
-			MSG_LOGV("pkt recv", msg);
+			PKT_LOGV("pkt recv", msg);
 		}
 		/* collect unused frames */
 		for (size_t i = n; i < nbatch; i++) {
@@ -176,7 +172,7 @@ static size_t pkt_recv(struct server *restrict s, const int fd)
 		msg->len = (size_t)nbrecv;
 		msg->ts = now;
 		q->mq_recv[q->mq_recv_len++] = msg;
-		MSG_LOGV("pkt recv", msg);
+		PKT_LOGV("pkt recv", msg);
 		s->stats.pkt_rx += nbrecv;
 		nrecv++;
 		navail--;
@@ -203,6 +199,7 @@ static size_t pkt_send_drop(struct pktqueue *restrict q)
 		msgframe_delete(q, q->mq_send[i]);
 	}
 	q->mq_send_len = 0;
+	LOGV_F("pkt send: dropping %zu packets", count);
 	return count;
 }
 
@@ -265,7 +262,7 @@ static size_t pkt_send(struct server *restrict s, const int fd)
 		for (size_t i = 0; i < n; i++) {
 			struct msgframe *restrict msg = q->mq_send[nsend + i];
 			nbsend += msg->len;
-			MSG_LOGV("pkt send", msg);
+			PKT_LOGV("pkt send", msg);
 			msgframe_delete(q, msg);
 		}
 		nsend += n;
@@ -318,7 +315,7 @@ static size_t pkt_send(struct server *restrict s, const int fd)
 	}
 	for (size_t i = 0; i < nsend; i++) {
 		struct msgframe *restrict msg = q->mq_send[i];
-		MSG_LOGV("pkt send", msg);
+		PKT_LOGV("pkt send", msg);
 		msgframe_delete(q, msg);
 	}
 	const size_t remain = count - nsend;

diff --git a/src/pktqueue.c b/src/pktqueue.c
@@ -28,6 +28,21 @@
 #include <stdint.h>
 #include <string.h>
 
+#define MSG_LOGV(what, msg)                                                    \
+	do {                                                                   \
+		if (!LOGLEVEL(VERBOSE)) {                                      \
+			break;                                                 \
+		}                                                              \
+		char addr[64];                                                 \
+		format_sa(&(msg)->addr.sa, addr, sizeof(addr));                \
+		LOG_F(VERBOSE, what ": %" PRIu16 " bytes, addr=%s",            \
+		      (msg)->len, addr);                                       \
+		FILE *log_fp = slog_file;                                      \
+		if (log_fp != NULL) {                                          \
+			print_bin(log_fp, "  ", (msg)->buf, (msg)->len);       \
+		}                                                              \
+	} while (0)
+
 #if WITH_CRYPTO
 
 static bool crypto_open_inplace(
@@ -88,6 +103,7 @@ static bool crypto_seal_inplace(
 
 static void queue_recv(struct server *restrict s, struct msgframe *restrict msg)
 {
+	MSG_LOGV("queue_recv", msg);
 	const unsigned char *kcp_packet = msg->buf + msg->off;
 	uint32_t conv = ikcp_getconv(kcp_packet);
 	if (conv == UINT32_C(0)) {
@@ -227,6 +243,7 @@ size_t queue_dispatch(struct server *restrict s)
 bool queue_send(struct server *restrict s, struct msgframe *restrict msg)
 {
 	struct pktqueue *restrict q = s->pkt.queue;
+	MSG_LOGV("queue_send", msg);
 #if WITH_CRYPTO
 	if (q->crypto != NULL) {
 		const size_t cap = MAX_PACKET_SIZE - (size_t)msg->off;

diff --git a/src/session.c b/src/session.c
@@ -621,7 +621,9 @@ ss0_on_connect(struct server *restrict s, struct msgframe *restrict msg)
 		return false;
 	}
 	if (!s->pkt.listened) {
-		LOGE("rendezvous connect: no server available");
+		char addr_str[64];
+		format_sa(&msg->addr.sa, addr_str, sizeof(addr_str));
+		LOGE_F("failed connecting %s: no server available", addr_str);
 		return true;
 	}
 	if (LOGLEVEL(INFO)) {