Merge pull request #402 from bfforever/kmesh-bpf-log-userspace

Kmesh eBPF log user space dumping

bpf/include/bpf_log.h

@@ -16,26 +16,105 @@
 #define BPF_LOGTYPE_SOCKOPS BPF_DEBUG_OFF
 #define BPF_LOGTYPE_XDP     BPF_DEBUG_OFF
 #define BPF_LOGTYPE_SENDMSG BPF_DEBUG_OFF
+#define MAX_MSG_LEN         255
+
 enum bpf_loglevel {
     BPF_LOG_ERR = 0,
     BPF_LOG_WARN,
     BPF_LOG_INFO,
     BPF_LOG_DEBUG,
 };
 
-#define BPF_LOG(l, t, f, ...)                                                                                          \
-    do {                                                                                                               \
-        int loglevel = BPF_MIN((int)BPF_LOG_LEVEL, ((int)BPF_LOG_DEBUG + (int)(BPF_LOGTYPE_##t)));                     \
-        if ((int)(BPF_LOG_##l) <= loglevel) {                                                                          \
-            char fmt[] = "[" #t "] " #l ": " f "";                                                                     \
-            bpf_trace_printk(fmt, sizeof(fmt), ##__VA_ARGS__);                                                         \
-        }                                                                                                              \
-    } while (0)
+struct log_event {
+    __u32 ret;
+    char msg[MAX_MSG_LEN];
+};
+struct {
+    __uint(type, BPF_MAP_TYPE_RINGBUF);
+    __uint(max_entries, 256 * 1024 /* 256 KB */);
+} kmesh_events SEC(".maps");
+
+struct {
+    __uint(type, BPF_MAP_TYPE_PERCPU_ARRAY);
+    __uint(max_entries, 1);
+    __type(key, int);
+    __type(value, struct log_event);
+} tmp_log_buf SEC(".maps");
+
+struct {
+    __uint(type, BPF_MAP_TYPE_ARRAY);
+    __uint(max_entries, 1);
+    __uint(key_size, sizeof(__u32));
+    __uint(value_size, sizeof(__u32));
+} bpf_log_level SEC(".maps");
 
 /* Add this macro to get ip addr from ctx variable, include bpf_sock_addr or bpf_sock_ops, weird
-reason is direct access would not be print ipaddr when pass `&ctx->remote_ipv4` to bpf_trace_printk */
+reason is that would not be print ipaddr, when directly pass `&ctx->remote_ipv4` to bpf_trace_printk, maybe ctx pass in
+to printk would be changed*/
 #define DECLARE_VAR_IPV4(ctx_ip, name)                                                                                 \
     __u32 name = 0;                                                                                                    \
     name = ctx_ip;
 
+#define DECLARE_VAR_IPV6(ctx_ip, name)                                                                                 \
+    __u32 name[4] = {0};                                                                                               \
+    name[0] = ctx_ip[0];                                                                                               \
+    name[1] = ctx_ip[1];                                                                                               \
+    name[2] = ctx_ip[2];                                                                                               \
+    name[3] = ctx_ip[3];
+
+/* Add KERNEL_VERSION_HIGHER_5_13_0 to resolve problem, which kernel version lower than 5.13, or linux distribution
+lower than 22.09, compile would report an error of bpf_snprintf dont exist */
+#if KERNEL_VERSION_HIGHER_5_13_0
+#define Kmesh_BPF_SNPRINTF(out, out_size, fmt, args...)                                                                \
+    ({                                                                                                                 \
+        unsigned long long ___param[___bpf_narg(args)];                                                                \
+                                                                                                                       \
+        _Pragma("GCC diagnostic push") _Pragma("GCC diagnostic ignored \"-Wint-conversion\"")                          \
+            ___bpf_fill(___param, args);                                                                               \
+        _Pragma("GCC diagnostic pop")                                                                                  \
+                                                                                                                       \
+            bpf_snprintf(out, out_size, fmt, ___param, sizeof(___param));                                              \
+    })
+
+#define BPF_LOG_U(fmt, args...)                                                                                        \
+    ({                                                                                                                 \
+        struct log_event *e;                                                                                           \
+        __u32 ret = 0;                                                                                                 \
+        int zero = 0;                                                                                                  \
+        e = bpf_map_lookup_elem(&tmp_log_buf, &zero);                                                                  \
+        if (!e)                                                                                                        \
+            break;                                                                                                     \
+        ret = Kmesh_BPF_SNPRINTF(e->msg, sizeof(e->msg), fmt, args);                                                   \
+        e->ret = ret;                                                                                                  \
+        if (ret < 0)                                                                                                   \
+            break;                                                                                                     \
+        bpf_ringbuf_output(&kmesh_events, e, sizeof(*e), 0);                                                           \
+    })
+#else
+#define BPF_LOG_U(fmt, args...)
+#endif
+
+static inline int map_lookup_log_level()
+{
+    int zero = 0;
+    int *value = NULL;
+    value = kmesh_map_lookup_elem(&bpf_log_level, &zero);
+    if (!value)
+        return 0;
+    return *value;
+}
+
+#define BPF_LOG(l, t, f, ...)                                                                                          \
+    do {                                                                                                               \
+        int level = map_lookup_log_level();                                                                            \
+        int loglevel = BPF_MIN((int)level, ((int)BPF_LOG_DEBUG + (int)(BPF_LOGTYPE_##t)));                             \
+        if ((int)(BPF_LOG_##l) <= loglevel) {                                                                          \
+            static const char fmt[] = "[" #t "] " #l ": " f "";                                                        \
+            if (!KERNEL_VERSION_HIGHER_5_13_0)                                                                         \
+                bpf_trace_printk(fmt, sizeof(fmt), ##__VA_ARGS__);                                                     \
+            else                                                                                                       \
+                BPF_LOG_U(fmt, ##__VA_ARGS__);                                                                         \
+        }                                                                                                              \
+    } while (0)
+
 #endif // _BPF_LOG_H_

bpf/include/common.h

@@ -87,4 +87,137 @@ static inline int kmesh_map_update_elem(void *map, const void *key, const void *
 
 #define GET_SKOPS_LOCAL_PORT(sk_ops) (__u16)((sk_ops)->local_port)
 
-#endif  // _COMMON_H_
+#define MAX_BUF_LEN 100
+#define MAX_IP4_LEN 16
+#define MAX_IP6_LEN 40
+
+struct buf {
+    char data[MAX_IP6_LEN];
+};
+struct {
+    __uint(type, BPF_MAP_TYPE_PERCPU_ARRAY);
+    __uint(max_entries, 1);
+    __type(key, int);
+    __type(value, struct buf);
+} tmp_buf SEC(".maps");
+
+#if KERNEL_VERSION_HIGHER_5_13_0
+static inline int convert_v4(char *data, __u32 *ip)
+{
+    int ret = 0;
+    ret = BPF_SNPRINTF(data, MAX_IP4_LEN, "%pI4h", ip);
+    return ret;
+}
+#else
+static inline int convert_v4(char *data, __u32 *ip_ptr)
+{
+    __u32 ip = *ip_ptr;
+    __u8 ip1 = (ip >> 24) & 0xFF;
+    __u8 ip2 = (ip >> 16) & 0xFF;
+    __u8 ip3 = (ip >> 8) & 0xFF;
+    __u8 ip4 = (ip >> 0) & 0xFF;
+
+    char tmp[MAX_IP4_LEN];
+    tmp[2] = '0' + (ip1 % 10);
+    ip1 /= 10;
+    tmp[1] = '0' + (ip1 % 10);
+    ip1 /= 10;
+    tmp[0] = '0' + (ip1 % 10);
+    tmp[3] = '.';
+
+    tmp[6] = '0' + (ip2 % 10);
+    ip2 /= 10;
+    tmp[5] = '0' + (ip2 % 10);
+    ip2 /= 10;
+    tmp[4] = '0' + (ip2 % 10);
+    tmp[7] = '.';
+
+    tmp[10] = '0' + (ip3 % 10);
+    ip3 /= 10;
+    tmp[9] = '0' + (ip3 % 10);
+    ip3 /= 10;
+    tmp[8] = '0' + (ip3 % 10);
+    tmp[11] = '.';
+
+    tmp[14] = '0' + (ip4 % 10);
+    ip4 /= 10;
+    tmp[13] = '0' + (ip4 % 10);
+    ip4 /= 10;
+    tmp[12] = '0' + (ip4 % 10);
+
+    *data++ = tmp[12];
+    *data++ = tmp[13];
+    *data++ = tmp[14];
+    *data++ = tmp[11];
+    *data++ = tmp[8];
+    *data++ = tmp[9];
+    *data++ = tmp[10];
+    *data++ = tmp[7];
+    *data++ = tmp[4];
+    *data++ = tmp[5];
+    *data++ = tmp[6];
+    *data++ = tmp[3];
+    *data++ = tmp[0];
+    *data++ = tmp[1];
+    *data++ = tmp[2];
+
+    *data = '\0';
+    return MAX_IP4_LEN;
+}
+#endif
+
+#if KERNEL_VERSION_HIGHER_5_13_0
+static inline int convert_v6(char *data, __u32 *ip6)
+{
+    int ret = 0;
+    ret = BPF_SNPRINTF(data, MAX_IP6_LEN, "%pI6", ip6);
+    return ret;
+}
+#else
+static const char hex_digits[16] = "0123456789abcdef";
+static inline int convert_v6(char *data, __u32 *ip6)
+{
+#pragma clang loop unroll(full)
+    for (int i = 0; i < 4; i++) {
+        __u32 ip = *(ip6 + i);
+        __u16 ip_1 = (ip >> 0) & 0xFFFF;
+        __u16 ip_2 = (ip >> 16) & 0xFFFF;
+        for (int j = 0; j < 2; j++) {
+            __u16 ip_1 = (ip)&0xFFFF;
+            __u8 h_1 = (ip_1 >> 0) & 0xFF;
+            __u8 h_2 = (ip_1 >> 8) & 0xFF;
+            *data++ = hex_digits[(h_1 >> 4) & 0xF];
+            *data++ = hex_digits[(h_1 >> 0) & 0xF];
+            *data++ = hex_digits[(h_2 >> 4) & 0xF];
+            *data++ = hex_digits[(h_2 >> 0) & 0xF];
+            *data++ = ':';
+            ip = ip >> 16;
+        }
+    }
+    data--;
+    *data = '\0';
+    return MAX_IP6_LEN;
+}
+#endif
+
+/* 2001:0db8:3333:4444:CCCC:DDDD:EEEE:FFFF */
+/* 192.168.000.001 */
+static inline char *ip2str(__u32 *ip_ptr, bool v4)
+{
+    struct buf *buf;
+    int zero = 0;
+    int ret;
+    buf = bpf_map_lookup_elem(&tmp_buf, &zero);
+    if (!buf)
+        return NULL;
+    if (v4) {
+        ret = convert_v4(buf->data, ip_ptr);
+    } else {
+        ret = convert_v6(buf->data, ip_ptr);
+    }
+    if (ret < 0)
+        return NULL;
+    return buf->data;
+}
+
+#endif // _COMMON_H_

bpf/kmesh/ads/cgroup_sock.c

@@ -36,7 +36,7 @@ static inline int sock4_traffic_control(struct bpf_sock_addr *ctx)
             return -ENOENT;
     }
     DECLARE_VAR_IPV4(ctx->user_ip4, ip);
-    BPF_LOG(DEBUG, KMESH, "bpf find listener addr=[%pI4h:%u]\n", &ip, bpf_ntohs(ctx->user_port));
+    BPF_LOG(DEBUG, KMESH, "bpf find listener addr=[%s:%u]\n", ip2str(&ip, 1), bpf_ntohs(ctx->user_port));
 
 #if ENHANCED_KERNEL
     // todo build when kernel support http parse and route

bpf/kmesh/ads/include/cluster.h

@@ -275,7 +275,7 @@ static inline int cluster_handle_loadbalance(Cluster__Cluster *cluster, address_
 
     ep_identity = cluster_get_ep_identity_by_lb_policy(eps, cluster->lb_policy);
     if (!ep_identity) {
-        BPF_LOG(ERR, CLUSTER, "cluster=\"%s\" handle lb failed, %u\n", name);
+        BPF_LOG(ERR, CLUSTER, "cluster=\"%s\" handle lb failed\n", name);
         return -EAGAIN;
     }
 
@@ -288,9 +288,9 @@ static inline int cluster_handle_loadbalance(Cluster__Cluster *cluster, address_
     BPF_LOG(
         INFO,
         CLUSTER,
-        "cluster=\"%s\", loadbalance to addr=[%pI4h:%u]\n",
+        "cluster=\"%s\", loadbalance to addr=[%s:%u]\n",
         name,
-        &sock_addr->ipv4,
+        ip2str(&sock_addr->ipv4, 1),
         bpf_ntohs(sock_addr->port));
     SET_CTX_ADDRESS(ctx, sock_addr);
     return 0;

bpf/kmesh/ads/include/filter.h

@@ -184,7 +184,7 @@ int filter_chain_manager(ctx_buff_t *ctx)
     /* filter match */
     ret = filter_chain_filter_match(filter_chain, &addr, ctx, &filter, &filter_idx);
     if (ret != 0) {
-        BPF_LOG(ERR, FILTERCHAIN, "no match filter, addr=%pI4h\n", &addr.ipv4);
+        BPF_LOG(ERR, FILTERCHAIN, "no match filter, addr=%s\n", ip2str(&addr.ipv4, 1));
         return KMESH_TAIL_CALL_RET(-1);
     }
 

bpf/kmesh/ads/include/listener.h

@@ -103,7 +103,12 @@ static inline int listener_manager(ctx_buff_t *ctx, Listener__Listener *listener
     /* filter chain match */
     ret = listener_filter_chain_match(listener, &addr, ctx, &filter_chain, &filter_chain_idx);
     if (ret != 0) {
-        BPF_LOG(WARN, LISTENER, "filterchain mismatch, unsupport addr=%pI4h:%u\n", &addr.ipv4, bpf_ntohs(addr.port));
+        BPF_LOG(
+            WARN,
+            LISTENER,
+            "filterchain mismatch, unsupport addr=%s:%u\n",
+            ip2str(&addr.ipv4, 1),
+            bpf_ntohs(addr.port));
         return -1;
     }
 

bpf/kmesh/ads/include/route_config.h

@@ -362,13 +362,13 @@ int route_config_manager(ctx_buff_t *ctx)
 
     virt_host = virtual_host_match(route_config, &addr, ctx);
     if (!virt_host) {
-        BPF_LOG(ERR, ROUTER_CONFIG, "failed to match virtual host, addr=%pI4h\n", &addr.ipv4);
+        BPF_LOG(ERR, ROUTER_CONFIG, "failed to match virtual host, addr=%s\n", ip2str(&addr.ipv4, 1));
         return KMESH_TAIL_CALL_RET(-1);
     }
 
     route = virtual_host_route_match(virt_host, &addr, ctx, (struct bpf_mem_ptr *)ctx_val->msg);
     if (!route) {
-        BPF_LOG(ERR, ROUTER_CONFIG, "failed to match route action, addr=%pI4h\n", &addr.ipv4);
+        BPF_LOG(ERR, ROUTER_CONFIG, "failed to match route action, addr=%s\n", ip2str(&addr.ipv4, 1));
         return KMESH_TAIL_CALL_RET(-1);
     }
 

bpf/kmesh/ads/sockops.c

@@ -35,9 +35,9 @@ static int sockops_traffic_control(struct bpf_sock_ops *skops, struct bpf_mem_pt
     BPF_LOG(
         DEBUG,
         SOCKOPS,
-        "sockops_traffic_control listener=\"%s\", addr=[%pI4h:%u]\n",
+        "sockops_traffic_control listener=\"%s\", addr=[%s:%u]\n",
         (char *)kmesh_get_ptr_val(listener->name),
-        &ip,
+        ip2str(&ip, 1),
         bpf_ntohs(skops->remote_port));
     return listener_manager(skops, listener, msg);
 }

bpf/kmesh/workload/cgroup_sock.c

@@ -22,13 +22,13 @@ static inline int sock4_traffic_control(struct kmesh_context *kmesh_ctx)
     DECLARE_FRONTEND_KEY(ctx, &kmesh_ctx->orig_dst_addr, frontend_k);
 
     DECLARE_VAR_IPV4(ctx->user_ip4, ip);
-    BPF_LOG(DEBUG, KMESH, "origin addr=[%pI4h:%u]\n", &ip, bpf_ntohs(ctx->user_port));
+    BPF_LOG(DEBUG, KMESH, "origin addr=[%s:%u]\n", ip2str(&ip, 1), bpf_ntohs(ctx->user_port));
     frontend_v = map_lookup_frontend(&frontend_k);
     if (!frontend_v) {
         return -ENOENT;
     }
 
-    BPF_LOG(DEBUG, KMESH, "bpf find frontend addr=[%pI4h:%u]\n", &ip, bpf_ntohs(ctx->user_port));
+    BPF_LOG(DEBUG, KMESH, "bpf find frontend addr=[%s:%u]\n", ip2str(&ip, 1), bpf_ntohs(ctx->user_port));
     ret = frontend_manager(kmesh_ctx, frontend_v);
     if (ret != 0) {
         if (ret != -ENOENT)

bpf/kmesh/workload/include/backend.h

@@ -59,8 +59,8 @@ backend_manager(struct kmesh_context *kmesh_ctx, backend_value *backend_v, __u32
         BPF_LOG(
             DEBUG,
             BACKEND,
-            "find waypoint addr=[%pI4h:%u]",
-            &backend_v->wp_addr.ip4,
+            "find waypoint addr=[%s:%u]\n",
+            ip2str(&backend_v->wp_addr.ip4, 1),
             bpf_ntohs(backend_v->waypoint_port));
         ret = waypoint_manager(kmesh_ctx, &backend_v->wp_addr, backend_v->waypoint_port);
         if (ret != 0) {
@@ -89,9 +89,9 @@ backend_manager(struct kmesh_context *kmesh_ctx, backend_value *backend_v, __u32
                     BPF_LOG(
                         DEBUG,
                         BACKEND,
-                        "get the backend addr=[%pI4h:%u]",
-                        &kmesh_ctx->dnat_ip.ip4,
-                        bpf_ntohs(kmesh_ctx->dnat_port));
+                        "get the backend addr=[%s:%u]\n",
+                        ip2str(&kmesh_ctx->dnat_ip.ip4, 1),
+                        bpf_ntohs(service_v->target_port[j]));
                     return 0;
                 }
             }

bpf/kmesh/workload/include/frontend.h

@@ -40,8 +40,8 @@ static inline int frontend_manager(struct kmesh_context *kmesh_ctx, frontend_val
             BPF_LOG(
                 DEBUG,
                 FRONTEND,
-                "find waypoint addr=[%pI4h:%u]",
-                &backend_v->wp_addr.ip4,
+                "find waypoint addr=[%s:%u]\n",
+                ip2str(&backend_v->wp_addr.ip4, 1),
                 bpf_ntohs(backend_v->waypoint_port));
             ret = waypoint_manager(kmesh_ctx, &backend_v->wp_addr, backend_v->waypoint_port);
             if (ret != 0) {