假设我现在有一个业务的性能问题:我fork了一个进程, 然后execv拉起这个进程, 在这个进程的main入口打印了一个log, 从fork成功的log到这个main函数的log竟然花费了2秒,要如何定位这个问题。
需要定位的拆分点:
那么有没有一种方案可以把这些都显示在一个时间线上。答案是lttng(因为是linux系统)
首先Lttng底层也是基于Ftrace来做。 所以我们用lttng抓一个trace就能看到调度器什么时候拉起来这个程序。但是我现在的问题是我发现进入我的main函数第一行很慢。这两个之间经历了什么, 要做的事情转换为用Lttng的机制想办法把从kernel到用户态的执行拉到同一时间线上来看。这就需要用:基于Lttng的自定义tracepoint的机制。
上demo,这里重点表达要怎么在自己的c++程序中加上一个lttng能采集到的trace点。
hello-tp.h
#undef TRACEPOINT_PROVIDER#define TRACEPOINT_PROVIDER my_provider /* 提供者名称 */#undef TRACEPOINT_INCLUDE#define TRACEPOINT_INCLUDE "./hello-tp.h"#if !defined(_HELLO_TP_H) || defined(TRACEPOINT_HEADER_MULTI_READ)#define _HELLO_TP_H#include <lttng/tracepoint.h>/* 定义具体的 Tracepoint 事件 */TRACEPOINT_EVENT( my_provider, /* 提供者名称 */ my_first_tracepoint, /* 事件名称 */ TP_ARGS( /* 传入的参数列表 */ int, my_integer_arg, char*, my_string_arg ), TP_FIELDS( /* 最终存入 trace 文件的字段 */ ctf_integer(int, my_int_field, my_integer_arg) ctf_string(my_str_field, my_string_arg) ))#endif /* _HELLO_TP_H */#include <lttng/tracepoint-event.h>hello-tp.c
#define TRACEPOINT_CREATE_PROBES#define TRACEPOINT_DEFINE#include "hello-tp.h"main.c
#include <stdio.h>#include <unistd.h>#include "hello-tp.h"int main(int argc, char **argv) { int i = 0; tracepoint(my_provider, my_first_tracepoint, i, "LTTng-custom-entry!"); // /* 这里就是你的自定义 Trace 点 */ printf("程序启动,准备打点...\n"); for (i = 0; i < 10; i++) { /* 这里就是你的自定义 Trace 点 */ tracepoint(my_provider, my_first_tracepoint, i, "LTTng-custom-test!"); usleep(1000000); // 模拟耗时 } return 0;}编译:
gcc -c -I. hello-tp.cgcc -c -I. main.cgcc -o hello-world main.o hello-tp.o -llttng-ust -ldl注意这里一定要加上:lttng enable-event -u my_provider:my_first_tracepoint 代表的是我要抓我上面自定义的用户态的 tracepoint .
#!/bin/bashlttng create s1lttng enable-event -k --syscall --alllttng enable-event -k sched_switch,sched_wak*,irq_*lttng add-context -k -t vtid -t vpid -t procname -t priolttng enable-event -u my_provider:my_first_tracepointlttng startsleep 10lttng stoplttng destroy然后运行上面的hello-world,然后执行上面的脚本。
打开要分析的trace 。 注意:这里吧ust和kernel的trace都要打开。
一清二楚的能看到:1:表示的是内核调度的开始时间。2:表示的用户态的trace,可以看到我第一行日志打印的时间。3:其他测试的自定义trace点。4: 时间间隔。
最后trace不会说谎,还能解决大家沟通问题,是个伟大的发明。
