2012/01/30

SystemTapで関数の呼び出し元を取得する

SystemTapはスクリプトで気軽にLinux Kernelの動作を調査できる素敵なツールです.
この記事は,SystemTapで関数の呼び出し元を取得する方法についてのメモです.
Tapset Referenceを参考にし,Context Functionsのfunction:callerを使用します.
最も簡単なものだと,このような形になります.


probe kernel.function("schedule").return {
  printf("caller : %s", caller())
}

出力はこんな感じ.Kernel内のschedule()関数を呼び出した関数名と,アドレスが出力されます.

[eiichi@fedora]~/work/stap% sudo stap schedule.stp
caller : cpu_idle 0xffffffffc04023d0
caller : cpu_idle 0xffffffffc04023d0
caller : run_ksoftirqd 0xffffffffc04558ed
caller : cpu_idle 0xffffffffc04023d0


さて,簡単な応用として,linux/kernel/sched.cで定義されているschedule()関数を呼び出している関数Top20を表示させてみましょう.
systemtap scriptは以下のようになります.


global callers

function print_top() {
  cnt=0
  printf("%-50s\tCount\n", "Caller")
  printf("---------------------------------\n")
  foreach( [name] in callers-) {
    printf("%-50s\t%5d\n", name, callers[name])
    if (cnt++ == 20)
      break
  }
  printf("---------------------------------\n")
}

probe kernel.function("schedule").return {
  callers[caller()]++
}

probe end {
  print_top()
  delete callers
}





eiichi@fedora]~/work/stap% sudo stap schedule_caller_top.stp -c "sleep 1"
Caller                                             Count
---------------------------------
cpu_idle 0xffffffffc04023d0                          332
worker_thread 0xffffffffc0468418                     166
schedule_hrtimeout_range_clock 0xffffffffc09202e7    116
futex_wait_queue_me 0xffffffffc047ec83                52
do_nanosleep 0xffffffffc0920158                       18
work_resched 0xffffffffc0921302                       17
schedule_timeout 0xffffffffc091fa05                   12
run_ksoftirqd 0xffffffffc04558ed                       8

---------------------------------




sleep ではcpu_idleが多くなります.
ちなみに,hackbenchを動かすと,このような感じです.

[eiichi@fedora]~/work/stap% sudo stap schedule_caller_top.stp -c "hackbench 10"
Running in process mode with 10 groups using 40 file descriptors each (== 400 tasks)
Each sender will pass 100 messages of 100 bytes
Time: 0.374
Caller                                             Count
---------------------------------
schedule_timeout 0xffffffffc091fa05                 1590
work_resched 0xffffffffc0921302                      735
cpu_idle 0xffffffffc04023d0                          349
worker_thread 0xffffffffc0468418                      83
rwsem_down_failed_common 0xffffffffc0920d25           22
schedule_hrtimeout_range_clock 0xffffffffc0920375     17
do_wait 0xffffffffc0452025                            10
schedule_hrtimeout_range_clock 0xffffffffc09202e7      5
run_ksoftirqd 0xffffffffc04558ed                       5
do_nanosleep 0xffffffffc0920158                        2
futex_wait_queue_me 0xffffffffc047ec83                 1
---------------------------------
ここで,schedule()関数ではなく,他の関数でも,呼び出し元Top20を表示させる場合を考えてみましょう.いちいちstap scriptを書き換えるのも面倒です.
付け焼刃的ですが,shell scriptと組み合わせると,簡単にできます.

#!/bin/sh
func=$1
cmd=$2
stap -e 'global callers
function print_top() {
  cnt=0
  printf("%-50s\tCount\n", "Caller")
  printf("---------------------------------\n")
  foreach( [name] in callers-) {
    printf("%-50s\t%5d\n", name, callers[name])
    if (cnt++ == 20)
      break
  }
  printf("---------------------------------\n")
}
probe kernel.function("'$func'").return {
  callers[caller()]++
}
probe end {
  print_top()
  delete callers
}' -c "$cmd"

使い方はこんな感じ.
linux/kernel/sched_fair.c のupdate_curr()関数で試してみました.
[eiichi@fedora]~/work/stap% sudo sh caller_top.sh update_curr "hackbench 10"
Running in process mode with 10 groups using 40 file descriptors each (== 400 tasks)
Each sender will pass 100 messages of 100 bytes
Time: 0.469
Caller                                             Count
---------------------------------
update_cfs_shares 0xffffffffc043c777               21460
put_prev_task_fair 0xffffffffc043d062              18516
dequeue_entity 0xffffffffc043cb79                  12369
enqueue_entity 0xffffffffc043d0e1                  12363
check_preempt_wakeup 0xffffffffc043c51f             9622
task_tick_fair 0xffffffffc043c90d                   1968
task_fork_fair 0xffffffffc043c308                    400
---------------------------------


ちなみにhackbench 10 は400個のtaskを生成するので,task_fork_fairからのupdate_curr呼び出し回数がちょうど400になってますね.

参考
RedHat Tapset Reference Manual