Skip to main content
 首页 » 操作系统

Linux tracer ftrace笔记(2)——添加与使用

2022年07月19日203lyhabc

 一、对于power相关的加trace

1. 在头文件trace/events/power.h中添加:

TRACE_EVENT(wakeup_reasons_tracer_test, 
        TP_PROTO(const char *irq_name, int choose_flag), 
        TP_ARGS(irq_name, choose_flag), 
        TP_STRUCT__entry( 
            __string(irq_name, irq_name) 
            __field(int, choose_flag) 
        ), 
        TP_fast_assign( 
            __assign_str(irq_name, irq_name); 
            __entry->choose_flag = choose_flag; 
        ), 
        TP_printk("irq_name=%s choose_flag=%d", 
              __get_str(irq_name), 
              __entry->choose_flag 
        ) 
);

trace中打印字符串比较少有但实用。

2. 源文件中使用

(1)  包含头文件

#include <trace/events/power.h>

(2)  函数中使用

int wakeup_reasons_tracer_test(const char *irq_name, int choose_flag) 
{ 
    ... 
    trace_wakeup_reasons_tracer_test(irq_name, choose_flag) 
    ... 
}

(3)  打开抓这个trace

# echo wakeup_reasons_tracer_test > /sys/kernel/tracing/set_event
# > /sys/kernel/tracing/trace //清空缓存
# cat /sys/kernel/tracing/trace_pipe | grep wakeup_reasons_tracer_test //查看wakeup_reasons_tracer_test调用

Binder:702_2-7684  [006] ....  2365.019705: wakeup_reasons_tracer_test: irq_name=abort choose_flag=16384 
Binder:702_2-7684  [000] d...  2366.087044: wakeup_reasons_tracer_test: irq_name=ccdetect-change choose_flag=248 
Binder:702_2-7684  [000] dnh1  2366.087295: wakeup_reasons_tracer_test: irq_name=ccdetect-change choose_flag=3 
      <idle>-0     [000] dnh1  2366.185204: wakeup_reasons_tracer_test: irq_name=alarm choose_flag=4

二、trace的filter功能

1.例子

# echo 1 > sched/sched_switch/enable 
# echo "next_comm == xxx" > sched/sched_switch/filter  (filter 格式可以cat format 同目录下获得) //测试失败
# echo "prev_prio==110" > /sys/kernel/tracing/events/sched/sched_switch/filter  //测试成功
# echo "prev_pid==6150" > /sys/kernel/tracing/events/sched/sched_switch/filter //成功,此例可以使用prev_pid和next_pid代替comm进行过滤
# echo 0 > /sys/kernel/tracing/events/sched/sched_switch/filter  //清空过滤
 
# echo 1 > sched/sched_wakeup/enable 
# echo "next_comm == xxx" > sched/sched_wakeup/filter 
 
# echo 1 > sched/sched_migrate/enable 
# echo "next_comm == xxx" > sched/sched_migrate/filter 
 
# echo 2048 > buffer_size_kb 
# echo 1 > tracing_on

三、补充

1. trace还可以使用模板

/* 
打印格式: sched_waking: comm=kworker/u16:5 pid=283 prio=120 target_cpu=003 
通过模板的方式打印的,格式由sched_wakeup_template里面配置的 
*/ 
DEFINE_EVENT(sched_wakeup_template, sched_waking, 
         TP_PROTO(struct task_struct *p), 
         TP_ARGS(p));

2. trace_printk

void set_user_nice(struct task_struct *p, long nice) 
{ 
    ... 
+   trace_printk("DEBUG: set_user_nice: pid=%d, nice_set=%d\n", p->pid, nice); 
    ... 
}

抓trace,然后以文本格式打开,中显示为:set_user_nice: DEBUG: set_user_nice: pid=7567, nice_set=-10,会自动给你添加上函数名。kernel中的高频打印可以使用trace_printk,其缺陷不可在解析后的trace上显示。

若想在trace解析后显示出来,5.10内核以后还可以使用如下方式:

//kernel/power/qos.c 
 
static noinline int tracing_mark_write(const char *buf) 
{ 
    trace_printk(buf); 
    return 0; 
} 
 
void freq_systrace_c(unsigned long freq, char *msg) 
{ 
    char buf[256]; 
 
    snprintf(buf, sizeof(buf), "C|9999|%s|%lu\n", msg, freq); //9999可以是任意值 
    tracing_mark_write(buf); 
} 
 
int freq_qos_update_request(struct freq_qos_request *req, s32 new_value) 
{ 
    if (!req) 
        return -EINVAL; 
 
    trace_printk("C|9999|TEST_%s_%d|%lu\n", current->comm, current->pid, new_value); //fail,trace解析后不会显示出来 
    trace_printk("C|9999|%s|%lu\n", current->comm, new_value); //fail,trace解析后不会显示出来 
    freq_systrace_c(new_value, current->comm); //success,trace解析可以显示出来 
    ... 
}

解析后在systrace上检索 9999,格式要严格对应上在解析后的trace上才能显示出来!

3. event_trace_printk

以文本格式打开抓取的trace,可以发现上层的trace都是通过 tracing_mark_write 写的,kernel里面也可以使用这个函数,其打印的内容可以在解析网站("chrome://tracing/" / "https://ui.perfetto.dev/#!/")上显示出来。常用打印格式:

event_trace_printk(tracing_mark_write_addr, "C|%d|%s|%d\n", pid, identify_string, value);

其中 tracing_mark_write_addr 是 tracing_mark_write 函数的地址,可以将函数的static属性去掉后直接使用 (unsigned long)tracing_mark_write 或使用 kallsyms_lookup_name("tracing_mark_write") 获取。

举例:tracing_mark_write: C|27183|my_str|12 解析后,在 "Process 27183" 这一栏中,在 "my_str" 标签里面,会显示 12 这个数值

参考:https://cpp.hotexamples.com/examples/-/-/event_trace_printk/cpp-event_trace_printk-function-examples.html

4. Native层调用内核的 /sys/kernel/tracing/trace_marker --> tracing_mark_write() 来往ftrace的ringbuffer里面写入数据,而内核函数调用其对应 probe 函数(也就是注册时指定的handler函数)往ftrace ringbuffer写入数据。


本文参考链接:https://www.cnblogs.com/hellokitty2/p/14165517.html