上手 dpdk trace 功能

dpdk 版本信息

EAL: RTE Version: 'DPDK 22.11.0-rc0'
1

trace 相关 dpdk 启动参数

dpdk trace 库的特性

    A framework to add tracepoints in control and fast path APIs with minimum impact on performance. Typical trace overhead is ~20 cycles and instrumentation overhead is 1 cycle.
    Enable and disable the tracepoints at runtime.
    Save the trace buffer to the filesystem at any point in time.
    Support overwrite and discard trace mode operations.
    String-based tracepoint object lookup.
    Enable and disable a set of tracepoints based on regular expression and/or globbing.
    Generate trace in Common Trace Format (CTF). CTF is an open-source trace format and is compatible with LTTng. For detailed information, refer to Common Trace Format.
1
2
3
4
5
6
7

从上面的描述可以看出，典型的跟踪开销约为 20 个时钟周期，检测开销为 1 个时钟周期，对现有框架性能的影响非常小。

testpmd 测试命令

添加 --trace 参数运行 testpmd，示例如下：

./dpdk-testpmd --trace='lib.*'
1

上述参数将会使能 lib 模块内的所有 trace point。

使用 babeltrace 工具查看 trace 结果：

babeltrace ~/dpdk-traces/rte-2022-10-23-AM-11-54-44/
1

trace 日志摘录如下：

[11:54:46.004817165] (+?.?????????) lib.eal.thread.lcore.ready: { cpu_id = 0x1, name = "lcore-worker-1" }, { lcore_id = 0x1, cpuset = "1" }
[11:54:46.005232029] (+0.000414864) lib.eal.thread.lcore.ready: { cpu_id = 0x2, name = "lcore-worker-2" }, { lcore_id = 0x2, cpuset = "2" }
[11:54:46.005364320] (+0.000132291) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x564312C9CDF0, arg = 0x0, worker_id = 0x1, rc = 0 }
[11:54:46.005389095] (+0.000024775) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x564312C9CDF0, arg = 0x0, worker_id = 0x2, rc = 0 }
[11:54:46.005626983] (+0.000237888) lib.eal.thread.lcore.ready: { cpu_id = 0x4, name = "lcore-worker-4" }, { lcore_id = 0x4, cpuset = "4" }
[11:54:46.005977395] (+0.000350412) lib.eal.thread.lcore.ready: { cpu_id = 0x5, name = "lcore-worker-5" }, { lcore_id = 0x5, cpuset = "5" }
[11:54:46.006195050] (+0.000217655) lib.eal.thread.lcore.ready: { cpu_id = 0x7, name = "lcore-worker-7" }, { lcore_id = 0x7, cpuset = "7" }
[11:54:46.006400263] (+0.000205213) lib.eal.thread.lcore.ready: { cpu_id = 0x6, name = "lcore-worker-6" }, { lcore_id = 0x6, cpuset = "6" }
[11:54:46.006615272] (+0.000215009) lib.eal.thread.lcore.ready: { cpu_id = 0x3, name = "lcore-worker-3" }, { lcore_id = 0x3, cpuset = "3" }
[11:54:46.006628120] (+0.000012848) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x564312C9CDF0, arg = 0x0, worker_id = 0x3, rc = 0 }
[11:54:46.006646933] (+0.000018813) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x564312C9CDF0, arg = 0x0, worker_id = 0x4, rc = 0 }
[11:54:46.006660999] (+0.000014066) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x564312C9CDF0, arg = 0x0, worker_id = 0x5, rc = 0 }
............................................................................................................
1
2
3
4
5
6
7
8
9
10
11
12
13

如上信息包含了事件触发的事件与事件内容信息，可以观测到一个 trace 点有多个日志，其中后半部分的 cpu_id 与 name 不同，这代表了不同的线程，dpdk trace 功能支持对多个 lcore 线程中的 trace 点进行跟踪。

trace 生成文件分析

生成的 trace 文件目录内容如下：

root@debian:~/dpdk-traces/rte-2022-10-23-AM-11-54-05# ls
channel0_0  channel0_1	channel0_2  channel0_3	channel0_4  channel0_5	channel0_6  channel0_7	channel0_8  channel0_9	metadata
1
2

channel0_x 中保存了每个 lcore 上的 trace 信息，meatdata 文件保存了 CTF 元数据，它们组成了一个 CTF trace。

CTF trace 的定义见下图：

一个 CTF trace 由一个 CTF metadata stream 与多个 CTF packet stream 组成，上文中的 channel0_x 就是多个 CTF packet stream，metadata 就是 CTF metadata stream，一个用于保存事件信息、一个用于描述事件属性。

metadata 内容示例如下：

/* CTF 1.8 */
typealias integer {size = 8; base = x;}:= uint8_t;
..................................................
typealias integer {size = 8; signed = false; encoding = ASCII; } := string_bounded_t;

typealias integer {size = 64; base = x;} := size_t;
...................................................
trace {
    major = 1;
    minor = 8;
    uuid = "00000da7-0075-4370-8f50-222ddd514176";
    byte_order = le;
    packet.header := struct {
	    uint32_t magic;
	    uint8_t  uuid[16];
    };
};

env {
    dpdk_version = "DPDK 22.11.0-rc0";
    tracer_name = "dpdk";
};

clock {
    name = "dpdk";
    freq =           1800000000;
    offset_s =          1666496302;
    offset =          1336619282;
};

typealias integer {
    size = 48; align = 1; signed = false;
    map = clock.dpdk.value;
} := uint48_clock_dpdk_t;

stream {
    packet.context := struct {
         uint32_t cpu_id;
         string_bounded_t name[32];
    };
    event.header := struct {
          uint48_clock_dpdk_t timestamp;
          uint16_t id;
    } align(64);
};
..........................................................
event {
    id = 69;
    name = "lib.mempool.create";
    fields := struct {
        string_bounded_t name[32];
        uint32_t nb_elts;
        uint32_t elt_size;
        uint32_t cache_size;
        uint32_t private_data_size;
        uintptr_t mp_init;
        uintptr_t mp_init_arg;
        uintptr_t obj_init;
        uintptr_t obj_init_arg;
        uint32_t flags;
        uintptr_t mempool;
        int32_t mempool_ops_index;
    };
};
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64

上述内容乍看上去比较像源代码，实际上它是基于 Trace Stream Description Language (TSDL) 这种描述型语言编写的元数据，它由如下几部分内容组成：

    Trace version
    Types available
    Per-trace event header description
    Per-stream event header description
    Per-stream event context description
    Per-event
        Event type to stream mapping
        Event type to name mapping
        Event type to ID mapping
        Event context description
        Event fields description
1
2
3
4
5
6
7
8
9
10
11

可以参照下图理解上面的代码内容：

其它解析工具

官网提到也可以使用 tracecompass 这个图形化工具来解析 CTF trace 数据，下载后发现它依赖 java 运行环境，由于本地缺少此环境，暂且跳过此工具。

参考链接

Common Trace Format v1.8.3
Trace Library