event trace tmp

Android开机过程开启ftrace某个event trace

比如对sched_stat_wait event进行trace，在rc文件里添加如下的行，开机完成后，cat trace就能得到此event的trace log(modprobe进程的)

    write /sys/kernel/debug/tracing/events/sched/sched_stat_wait/filter "delay>1000000 && comm=='modprobe'"
    write /sys/kernel/debug/tracing/events/sched/sched_stat_wait/enable 1
    write /sys/kernel/debug/tracing/buffer_size_kb 3072
    write /sys/kernel/debug/tracing/tracing_on 1
    #some interested action, ex. modprobe
    write /sys/kernel/debug/tracing/tracing_on 0

如果没有设置成功，比如开机后cat sched_stat_wait/enable值为0，检查下是不是违法了selinux rule了，比如上面的write sched_stat_wait/enable 1有碰到违反了selinux rule导致没有enable，将selinux关了就能enable了，这里违反的selinux rule log如下：

[    2.481131] type=1400 audit(2.479:8): avc: denied { write } for comm="init" name="enable" dev="tracefs" ino=2551 scontext=u:r:vendor_init:s0 tcontext=u:object_r:debugfs_tracing_debug:s0 tclass=file permissive=0

event trace filter格式

field-name relation-operatior value

• 对于数字域，可以使用操作符==, !=, <, <=, >, >=, &
• 对于字符串域，可以使用==, !=, ~。目前字符串只支持完全匹配，且最多可以组合16个条件。”~”支持通配符(*,?)。

例子：

/d/tracing/events/sched/sched_stat_wait
echo 'delay>1000 && comm=="bash"' >filter

sched_stat_wait

       perf 27484 [000] 93115.326708: sched:sched_stat_wait: comm=kworker/0:1 pid=142 delay=2683863 [ns]
sched_stat_wait even tells us that the task was sitting there for 2.68ms waiting for the CPU.

    swapper     0 [000] 93115.013231: sched:sched_stat_wait: comm=kworker/0:1 pid=142 delay=0 [ns]
sched_stat_wait says delay=0 meaning that the kworker/0:1 tasks did not wait at all to be scheduled. As soon as it was ready to run, it was allowed to. Great.

from: http://notes.secretsauce.net/notes/2015/09/05_a-kernel-debugging-story.html

sched相关的event

reference

ftrace code flow: https://zhuanlan.zhihu.com/p/465155262