使用ftrace的事件加强其他的追踪器输出
ftrace的追踪事件可以与其他插件追踪器组合输出。这样就可以更清晰地查看输出量较多的函数追踪器的结果等。
例如,尝试同时使用进程调度程序的相关事件和函数追踪器,就可以得知进程的切换处理和函数调用关系等。在下例中实际显示了从发生sched_switch事件到进程切换为止的步骤,可以更加详细地了解事件前后发生的情况。
[tracing]#echo'sched:*'>set_event
[tracing]#echo'function'>current_tracer
[tracing]#cat trace
……
less-3569[001]16957.997983:sched_stat_wait:comm=events/1 pid=10
delay=53796[ns]
less-3569[001]16957.997984:task_of<-pick_next_task_fair
less-3569[001]16957.997984:hrtickstart_fair<-pick_next
task_fair
less-3569[001]16957.997985:_raw_local_save_flags<-ftrace
raw_event_sched_switch
less-3569[001]16957.997985:sched_switch:prev_comm=less
prev_pid=3569 prev_prio=120 prev_state=R==>next_comm=events/1 next_pid=10 next_prio=120
less-3569[001]16957.997985:atomic_inc<-schedule
less-3569[001]16957.997986:enter_lazy_tlb.clone.16
<-schedule
less-3569[001]16957.997986:native_load_sp0<-__switch_to
less-3569[001]16957.997987:load_TLS<-__switch_to
less-3569[001]16957.997987:native_load_tls<-load_TLS
less-3569[001]16957.997988:unlazy_fpu<-switch_to
less-3569[001]16957.997988:read_cr0<-__unlazy_fpu
less-3569[001]16957.997988:native_read_cr0<-read_cr0
less-3569[001]16957.997989:native_write_cr0<-__unlazy_fpu
events/1-10[001]16957.997995:finish_task_switch<-schedule
events/1-10[001]16957.997999:rawlocal_irq_enable<-finish_task
switch
另外,还可以使用事件的参数,研究函数调用的终点实际进行的处理和处理所花费的时间之间的关系。
[tracing]#echo do_IRQ>set_ftrace_flter
[tracing]#echo 1>events/irq/irq_handler_entry/enable
[tracing]#echo function_graph>current_tracer
[tracing]#cat trace
……
0)==========>|
0)|do_IRQ(){
0)|/irq_handler_entry:irq=19 name=ehci_hcd:usb1/
0)|/irq_handler_entry:irq=19 name=virtio0/
0)!244.859 us|}
0)<==========|
0)==========>|
0)|do_IRQ(){
0)|/irq_handler_entry:irq=21 name=ahci/
0)|/irq_handler_entry:irq=21 name=Intel 82801AA-ICH/
0)==========>|
0
)|do_IRQ(){
0)|/irq_handler_entry:irq=21 name=ahci/
0)|/irq_handler_entry:irq=21 name=Intel 82801AA-ICH/
0)!286.214 us|}
0)<==========|
0)!620.506 us|}
0)<==========|
例如,这里就使用do_IRQ的函数调用图表显示了处理所花费的时间(出现了超过100微秒的数值,因此数值前面显示了‘!’),但是仅使用函数调用图表难以调查出哪个中断进行了什么处理。但是事件会显示各个中断的处理方式,这样就可以很简单地得知启动了哪个中断处理程序,以及此时花费了多少时间。