From 03eabf12b7d486278598ad44d2b7d8e310ff0abf Mon Sep 17 00:00:00 2001
From: yangchen <yangchen145@huawei.com>
Date: Sun, 4 Feb 2024 13:29:15 +0800
Subject: [PATCH] gazellectl: support send latency show

---
 src/common/dpdk_common.h            |  10 +++
 src/common/gazelle_dfx_msg.h        |  20 ++++-
 src/lstack/core/lstack_lwip.c       |  14 +++-
 src/lstack/core/lstack_stack_stat.c |  15 ++--
 src/lstack/netif/lstack_ethdev.c    |   4 +
 src/ltran/ltran_dfx.c               | 110 +++++++++++++++-------------
 6 files changed, 111 insertions(+), 62 deletions(-)

diff --git a/src/common/dpdk_common.h b/src/common/dpdk_common.h
index 38f09ae..a79a0f2 100644
--- a/src/common/dpdk_common.h
+++ b/src/common/dpdk_common.h
@@ -95,6 +95,16 @@ static __rte_always_inline void time_stamp_into_mbuf(uint32_t rx_count, struct r
     }
 }
 
+static __rte_always_inline void time_stamp_into_pbuf(uint32_t tx_count, struct pbuf *buf[], uint64_t time_stamp)
+{
+    struct latency_timestamp *lt;
+    for (uint32_t i = 0; i < tx_count; i++) {
+        lt = &pbuf_to_private(buf[i])->lt;
+        lt->stamp = time_stamp;
+        lt->check = ~(time_stamp);
+    }
+}
+
 bool get_kni_started(void);
 struct rte_kni* get_gazelle_kni(void);
 int32_t dpdk_kni_init(uint16_t port, struct rte_mempool *pool);
diff --git a/src/common/gazelle_dfx_msg.h b/src/common/gazelle_dfx_msg.h
index d465efa..d47ed9a 100644
--- a/src/common/gazelle_dfx_msg.h
+++ b/src/common/gazelle_dfx_msg.h
@@ -24,6 +24,10 @@
 /* maybe it should be consistent with MEMP_NUM_TCP_PCB */
 #define GAZELLE_LSTACK_MAX_CONN          (20000 + 2000) // same as MAX_CLIENTS + RESERVED_CLIENTS in lwipopts.h
 
+#define GAZELLE_RESULT_LEN               4096
+#define GAZELLE_MAX_LATENCY_TIME         1800 // max latency time 30mins
+#define GAZELLE_RESULT_LINE_LEN          80   // for a single row, the max len of result is 80
+
 enum GAZELLE_STAT_MODE {
     GAZELLE_STAT_LTRAN_SHOW = 0,
     GAZELLE_STAT_LTRAN_SHOW_RATE,
@@ -54,8 +58,11 @@ enum GAZELLE_STAT_MODE {
 };
 
 enum GAZELLE_LATENCY_TYPE {
-    GAZELLE_LATENCY_LWIP,
-    GAZELLE_LATENCY_READ,
+    GAZELLE_LATENCY_READ_LWIP,
+    GAZELLE_LATENCY_READ_LSTACK,
+    GAZELLE_LATENCY_WRITE_LWIP,
+    GAZELLE_LATENCY_WRITE_LSTACK,
+    GAZELLE_LATENCY_MAX,
 };
 
 struct gazelle_stack_stat {
@@ -216,9 +223,14 @@ struct stack_latency {
     uint64_t latency_total;
 };
 
+struct gazelle_latency_result {
+    int latency_stat_index;
+    struct stack_latency latency_stat_record;
+    char latency_stat_result[GAZELLE_RESULT_LEN];
+};
+
 struct gazelle_stack_latency {
-    struct stack_latency read_latency;
-    struct stack_latency lwip_latency;
+    struct stack_latency latency[GAZELLE_LATENCY_MAX];
     uint64_t start_time;
     uint64_t g_cycles_per_us;
 };
diff --git a/src/lstack/core/lstack_lwip.c b/src/lstack/core/lstack_lwip.c
index 22605dd..be2c6de 100644
--- a/src/lstack/core/lstack_lwip.c
+++ b/src/lstack/core/lstack_lwip.c
@@ -244,6 +244,11 @@ struct pbuf *do_lwip_get_from_sendring(struct lwip_sock *sock, uint16_t remain_s
     if (pbuf == NULL) {
         return NULL;
     }
+
+    if (get_protocol_stack_group()->latency_start) {
+        calculate_lstack_latency(&sock->stack->latency, pbuf, GAZELLE_LATENCY_WRITE_LWIP);
+    }
+
     sock->send_pre_del = pbuf;
 
     if (!gazelle_ring_readover_count(sock->send_ring)) {
@@ -303,6 +308,11 @@ static inline ssize_t app_buff_write(struct lwip_sock *sock, void *buf, size_t l
 
     (void)gazelle_ring_read(sock->send_ring, (void **)pbufs, write_num);
 
+    if (get_protocol_stack_group()->latency_start) {
+        uint64_t time_stamp = get_current_time();
+        time_stamp_into_pbuf(write_num, pbufs, time_stamp);
+    }
+
     ssize_t send_len = do_app_write(pbufs, buf, len, write_num);
 
     if (addr) {
@@ -573,7 +583,7 @@ ssize_t do_lwip_read_from_lwip(struct lwip_sock *sock, int32_t flags, u8_t apifl
 
     for (uint32_t i = 0; get_protocol_stack_group()->latency_start && i < read_count; i++) {
         if (pbufs[i] != NULL) {
-            calculate_lstack_latency(&sock->stack->latency, pbufs[i], GAZELLE_LATENCY_LWIP);
+            calculate_lstack_latency(&sock->stack->latency, pbufs[i], GAZELLE_LATENCY_READ_LWIP);
         }
     }
 
@@ -895,7 +905,7 @@ ssize_t do_lwip_read_from_stack(int32_t fd, void *buf, size_t len, int32_t flags
                 sock->wakeup->stat.app_read_cnt += 1;
             }
             if (latency_enable) {
-                calculate_lstack_latency(&sock->stack->latency, pbuf, GAZELLE_LATENCY_READ);
+                calculate_lstack_latency(&sock->stack->latency, pbuf, GAZELLE_LATENCY_READ_LSTACK);
             }
             gazelle_ring_read_over(sock->recv_ring);
 
diff --git a/src/lstack/core/lstack_stack_stat.c b/src/lstack/core/lstack_stack_stat.c
index 23571b4..cb11dc3 100644
--- a/src/lstack/core/lstack_stack_stat.c
+++ b/src/lstack/core/lstack_stack_stat.c
@@ -53,8 +53,9 @@ void calculate_lstack_latency(struct gazelle_stack_latency *stack_latency, const
 {
     uint64_t latency;
     const struct latency_timestamp *lt;
+    struct stack_latency *latency_stat;
 
-    if (pbuf == NULL) {
+    if (pbuf == NULL || type >= GAZELLE_LATENCY_MAX) {
         return;
     }
 
@@ -62,10 +63,9 @@ void calculate_lstack_latency(struct gazelle_stack_latency *stack_latency, const
     if (lt->stamp != ~(lt->check) || lt->stamp < stack_latency->start_time) {
         return;
     }
-    latency = get_current_time() - lt->stamp;
 
-    struct stack_latency *latency_stat = (type == GAZELLE_LATENCY_LWIP) ?
-        &stack_latency->lwip_latency : &stack_latency->read_latency;
+    latency = get_current_time() - lt->stamp;
+    latency_stat = &stack_latency->latency[type];
 
     latency_stat->latency_total += latency;
     latency_stat->latency_max = (latency_stat->latency_max > latency) ? latency_stat->latency_max : latency;
@@ -118,8 +118,11 @@ static void set_latency_start_flag(bool start)
             LSTACK_LOG(ERR, LSTACK, "memset_s faile\n");
         }
         stack->latency.start_time = get_current_time();
-        stack->latency.lwip_latency.latency_min = ~((uint64_t)0);
-        stack->latency.read_latency.latency_min = ~((uint64_t)0);
+
+        for (uint32_t j = 0; j < GAZELLE_LATENCY_MAX; j++) {
+            stack->latency.latency[j].latency_min = ~((uint64_t)0);
+        }
+ 
         memset_s(&stack->aggregate_stats, sizeof(struct gazelle_stack_aggregate_stats),
             0, sizeof(stack->aggregate_stats));
     }
diff --git a/src/lstack/netif/lstack_ethdev.c b/src/lstack/netif/lstack_ethdev.c
index 4d6f620..94ecffc 100644
--- a/src/lstack/netif/lstack_ethdev.c
+++ b/src/lstack/netif/lstack_ethdev.c
@@ -889,6 +889,10 @@ static err_t eth_dev_output(struct netif *netif, struct pbuf *pbuf)
 
         pre_mbuf = mbuf;
         rte_mbuf_refcnt_update(mbuf, 1);
+
+        if (get_protocol_stack_group()->latency_start) {
+            calculate_lstack_latency(&stack->latency, pbuf, GAZELLE_LATENCY_WRITE_LSTACK);
+        }
         pbuf = pbuf->next;
     }
 
diff --git a/src/ltran/ltran_dfx.c b/src/ltran/ltran_dfx.c
index 4b246a1..ecdb5f9 100644
--- a/src/ltran/ltran_dfx.c
+++ b/src/ltran/ltran_dfx.c
@@ -50,9 +50,6 @@
 #define GAZELLE_CMD_MAX          5
 #define CMD_WAIT_TIME            1   // sec
 
-#define GAZELLE_RESULT_LEN       8291
-#define GAZELLE_MAX_LATENCY_TIME 1800    // max latency time 30mins
-
 #define GAZELLE_DECIMAL          10
 #define GAZELLE_KEEPALIVE_STR_LEN 35
 #define GAZELLE_TIME_STR_LEN 25
@@ -702,8 +699,8 @@ static void parse_thread_latency_result(const struct stack_latency *latency, cha
 {
     if (latency->latency_pkts > 0) {
         *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", latency->latency_pkts);
-        *pos += sprintf_s(result + *pos, max_len, "%-6"PRIu64"      ", latency->latency_min);
-        *pos += sprintf_s(result + *pos, max_len, "%-6"PRIu64"      ", latency->latency_max);
+        *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", latency->latency_min);
+        *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", latency->latency_max);
         *pos += sprintf_s(result + *pos, max_len, "%-6.2f \n",
             (double)latency->latency_total / latency->latency_pkts);
     } else {
@@ -719,52 +716,53 @@ static void parse_thread_latency_result(const struct stack_latency *latency, cha
 static void parse_latency_total_result(char *result, size_t max_len, int32_t *pos,
     const struct stack_latency *record)
 {
+    if (max_len < GAZELLE_RESULT_LINE_LEN) {
+        printf("total latency result show failed, out of memory bounds\n");
+        return;
+    }
+
     if (record->latency_pkts > 0) {
-        *pos += sprintf_s(result + *pos, max_len, "                          total:      ");
+        *pos += sprintf_s(result + *pos, max_len, "                     total:           ");
         *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", record->latency_pkts);
-        *pos += sprintf_s(result + *pos, max_len, "%-6"PRIu64"      ", record->latency_min);
-        *pos += sprintf_s(result + *pos, max_len, "%-6"PRIu64"      ", record->latency_max);
-        *pos += sprintf_s(result + *pos, max_len, "%-6.2f \n\n\n",
+        *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", record->latency_min);
+        *pos += sprintf_s(result + *pos, max_len, "%-8"PRIu64"    ", record->latency_max);
+        *pos += sprintf_s(result + *pos, max_len, "%-6.2f \n\n",
             (double)record->latency_total / record->latency_pkts);
     } else {
-        *pos += sprintf_s(result + *pos, max_len, "                          total:      0\n\n\n");
+        *pos += sprintf_s(result + *pos, max_len, "                     total:           0\n\n");
     }
 }
 
-static void gazelle_print_lstack_stat_latency(void *buf, const struct gazelle_stat_msg_request *req_msg)
+static void gazelle_show_latency_result(const struct gazelle_stat_msg_request *req_msg,
+                                        struct gazelle_stack_dfx_data *stat, struct stack_latency *latency,
+                                        struct gazelle_latency_result *res)
 {
-    struct gazelle_stack_dfx_data *stat = (struct gazelle_stack_dfx_data *)buf;
-    struct gazelle_stack_latency *latency = &stat->data.latency;
-    int32_t ret = GAZELLE_OK;
-    int32_t lwip_index = 0;
-    int32_t read_index = 0;
-    struct stack_latency lwip_record = {0};
-    struct stack_latency read_record = {0};
-    char str_ip[GAZELLE_SUBNET_LENGTH_MAX] = {0};
+    char str_ip[GAZELLE_SUBNET_LENGTH_MAX] = { 0 };
 
-    read_record.latency_min = ~((uint64_t)0);
-    lwip_record.latency_min = ~((uint64_t)0);
-
-    char *lwip_result = calloc(GAZELLE_RESULT_LEN, sizeof(char));
-    if (lwip_result == NULL) {
-        return;
-    }
-    char *read_result = calloc(GAZELLE_RESULT_LEN, sizeof(char));
-    if (read_result == NULL) {
-        free(lwip_result);
+    if (GAZELLE_RESULT_LEN - res->latency_stat_index < GAZELLE_RESULT_LINE_LEN) {
+        printf("too many threads show latency result, out of memory bounds\n");
         return;
     }
 
-    do {
-        lwip_index += sprintf_s(lwip_result + lwip_index, (size_t)(GAZELLE_RESULT_LEN - lwip_index),
-            "ip: %-15s  tid: %-8u    ", inet_ntop(AF_INET, &req_msg->ip, str_ip, sizeof(str_ip)), stat->tid);
-        parse_thread_latency_result(&latency->lwip_latency, lwip_result, (size_t)(GAZELLE_RESULT_LEN - lwip_index),
-            &lwip_index, &lwip_record);
+    res->latency_stat_index += sprintf_s(res->latency_stat_result + res->latency_stat_index,
+        (size_t)(GAZELLE_RESULT_LEN - res->latency_stat_index), "ip: %-15s  tid: %-8u    ",
+        inet_ntop(AF_INET, &req_msg->ip, str_ip, sizeof(str_ip)), stat->tid);
 
-        read_index += sprintf_s(read_result + read_index, (size_t)(GAZELLE_RESULT_LEN - read_index),
-            "ip: %-15s  tid: %-8u    ", inet_ntop(AF_INET, &req_msg->ip, str_ip, sizeof(str_ip)), stat->tid);
-        parse_thread_latency_result(&latency->read_latency, read_result, (size_t)(GAZELLE_RESULT_LEN - read_index),
-            &read_index, &read_record);
+    parse_thread_latency_result(latency, res->latency_stat_result,
+        (size_t)(GAZELLE_RESULT_LEN - res->latency_stat_index), &res->latency_stat_index, &res->latency_stat_record);
+}
+
+static void gazelle_show_latency_result_total(void *buf, const struct gazelle_stat_msg_request *req_msg,
+                                              struct gazelle_latency_result *res)
+{
+    int ret = GAZELLE_OK;
+    struct gazelle_stack_dfx_data *stat = (struct gazelle_stack_dfx_data *)buf;
+    struct gazelle_stack_latency *latency = &stat->data.latency;
+
+    do {
+        for (int i = 0; i < GAZELLE_LATENCY_MAX; i++) {
+            gazelle_show_latency_result(req_msg, stat, &latency->latency[i], &res[i]);
+        }
 
         if ((stat->eof != 0) || (ret != GAZELLE_OK)) {
             break;
@@ -772,21 +770,33 @@ static void gazelle_print_lstack_stat_latency(void *buf, const struct gazelle_st
         ret = dfx_stat_read_from_ltran(buf, sizeof(struct gazelle_stack_dfx_data), req_msg->stat_mode);
     } while (true);
 
-    parse_latency_total_result(lwip_result, (size_t)(GAZELLE_RESULT_LEN - lwip_index), &lwip_index, &lwip_record);
-    parse_latency_total_result(read_result, (size_t)(GAZELLE_RESULT_LEN - read_index), &read_index, &read_record);
+    for (int i = 0; i < GAZELLE_LATENCY_MAX; i++) {
+        parse_latency_total_result(res[i].latency_stat_result, (size_t)(GAZELLE_RESULT_LEN - res[i].latency_stat_index),
+            &res[i].latency_stat_index, &res[i].latency_stat_record);
+    }
+}
+
+static void gazelle_print_lstack_stat_latency(void *buf, const struct gazelle_stat_msg_request *req_msg)
+{
+    struct gazelle_latency_result *res = calloc(GAZELLE_LATENCY_MAX, sizeof(struct gazelle_latency_result));
+    if (res == NULL) {
+        return;
+    }
+
+    for (int i = 0; i < GAZELLE_LATENCY_MAX; i++) {
+        res[i].latency_stat_record.latency_min = ~((uint64_t)0);
+    }
 
-    printf("Statistics of lstack latency: t0--->t3 \
-        (t0:read form nic  t1:into lstask queue  t2:into app queue t3:app read)\n");
-    printf("                                      pkts        min(us)     max(us)     average(us)\n%s",
-        read_result);
+    gazelle_show_latency_result_total(buf, req_msg, res);
 
-    printf("Statistics of lstack latency: t0--->t2 \
-        (t0:read form nic  t1:into lstask queue  t2:into app queue t3:app read)\n");
-    printf("                                      pkts        min(us)     max(us)     average(us)\n%s",
-        lwip_result);
+    printf("Statistics of lstack latency          pkts        min(us)     max(us)     average(us)\n");
+    printf("range: t0--->t3\n%s", res[GAZELLE_LATENCY_READ_LSTACK].latency_stat_result);
+    printf("range: t0--->t2\n%s", res[GAZELLE_LATENCY_READ_LWIP].latency_stat_result);
+    printf("range: t3--->t0\n%s", res[GAZELLE_LATENCY_WRITE_LSTACK].latency_stat_result);
+    printf("range: t2--->t0\n%s", res[GAZELLE_LATENCY_WRITE_LWIP].latency_stat_result);
+    printf("t0:read form/send to nic  t1:into/out of lstask queue  t2:into/out of app queue t3:app read/send\n");
 
-    free(read_result);
-    free(lwip_result);
+    free(res);
 }
 
 static void gazelle_print_lstack_stat_lpm(void *buf, const struct gazelle_stat_msg_request *req_msg)
-- 
2.27.0