概要

CentOS6.9でSystemTapを使ってみた時の自分メモ。深く使ったわけでもないので、使いながら随時更新予定。

インストール

必要なもの

kernel-devel(実行しているカーネルバージョン)
- インストール方法　→ https://wiki.centos.org/HowTos/I_need_the_Kernel_Source
- wgetしてrpm -ivhする
kernel-debuginfo(実行しているカーネルバージョン)
- yum install yum-utilsでdebuginfo-installコマンドをインストール
- debuginfo-install kernel-uname -r``
- yumでインストールするとcentos.plusみたいなものがインストールされてしまう
kernel-debuginfo-common-arch(実行しているカーネルバージョン)
- kernel-debuginfoをインストールで一緒にインストールされる
gcc
systemtap

`kernel-devel`とは

カーネルモジュール.koを作成するために必要なもの。systemtapではカーネルモジュールを作成するので必要になる。

Description :
This package provides kernel headers and makefiles sufficient to build modules
against the kernel package.

`kernel-debuginfo`とは

カーネルのdebug情報。/boot以下のカーネルのマップ情報から得られるものとは異なる？？カーネルモジュール用にまた何かあるのだろうか？

Description :
This package provides debug information for package kernel.
This is required to use SystemTap with kernel-2.6.32-642.15.1.el6.x86_64.

インストールの確認

stap -v -e 'probe vfs.read {printf("read performed\n"); exit()}'
エラーがなければOK

SystemTapの実行

sudo stap -v ファイル.stp

-vをつけてることでどこまで実行されたのかを確認したほうがよい。-eでワンライナーでも実行できる。
/usr/share/systemtap/tapsetに沢山のサンプルがある

SystemTap書式

各プローブ(測定ポイント)を以下の様に指定する。プローブで指定したカーネル関数などのプローブポイントが呼び出されたタイミングで{}の中を実行して観測できる。プローブ.returnでそのプローブポイントが終了するタイミングで呼べる。

probe プローブ {statements}

下の場合だと、カーネル関数のsys_syncが呼び出された時に{}の中が実行される。

global count=0

probe kernel.function("sys_sync") {
  count++
  printf( "sys_sync called %d times, currently by pid %d\n", count, pid );
}

プローブポイント一覧

stap -Lでポイントの一覧が確認できる。


# VFSのfile_operationイベントのブローブポイント一覧
stap -L vfs.*
# カーネル関数のブローブポイント一覧
stap -L 'kernel.function("*")'
#静的ブローブポイント一覧
stap -L 'kernel.trace("*")'
#モジュール内の関数のプローブポイント一覧
stap -L 'module("*").function("*")'

例
- vfsでは下記の関数とその関数に関して利用できる型がある


$ stap -L vfs.*
vfs.__set_page_dirty_buffers dev:long devname:string ino:long index:long name:string argstr:string size:long units:string $page:struct page*
vfs.add_to_page_cache dev:long devname:string ino:long index:long nrpages:long size:long units:string name:string argstr:string $page:struct page* $mapping:struct address_space* $offset:long unsigned int $gfp_mask:gfp_t
vfs.block_sync_page dev:long devname:string ino:long index:long name:string argstr:string size:long units:string $page:struct page*
vfs.buffer_migrate_page dev:long ino:long devname:string index:long name:string argstr:string size:long units:string $mapping:struct address_space* $newpage:struct page* $page:struct page*
vfs.do_mpage_readpage dev:long devname:string ino:long index:long name:string argstr:string size:long units:string $bio:struct bio* $page:struct page* $nr_pages:unsigned int $last_block_in_bio:sector_t* $map_bh:struct buffer_head* $first_logical_block:long unsigned int* $get_block:get_block_t* $blocks:sector_t[]
vfs.do_sync_read dev:long devname:string ino:long file:long len:long pos:long buf:long name:string argstr:string size:long units:string bytes_to_read:long $filp:struct file* $buf:char* $len:size_t $ppos:loff_t* $iov:struct iovec $kiocb:struct kiocb
vfs.do_sync_write dev:long devname:string ino:long file:long len:long pos:long buf:long bytes_to_write:long name:string argstr:string size:long units:string $filp:struct file* $buf:char const* $len:size_t $ppos:loff_t* $iov:struct iovec $kiocb:struct kiocb
vfs.read file:long pos:long buf:long bytes_to_read:long dev:long devname:string ino:long name:string argstr:string $file:struct file* $buf:char* $count:size_t $pos:loff_t*
vfs.readv file:long dev:long devname:string ino:long pos:long vec:long vlen:long bytes_to_read:long name:string argstr:string $file:struct file* $vec:struct iovec const* $vlen:long unsigned int $pos:loff_t*
vfs.remove_from_page_cache dev:long devname:string ino:long index:long name:string argstr:string $page:struct page*
vfs.write file:long pos:long buf:long bytes_to_write:long dev:long devname:string ino:long name:string argstr:string $file:struct file* $buf:char const* $count:size_t $pos:loff_t*
vfs.writev file:long dev:long devname:string ino:long pos:long vlen:long vec:long bytes_to_write:long name:string argstr:string $file:struct file* $vec:struct iovec const* $vlen:long unsigned int $pos:loff_t*

SystemTapの仕組み

https://www.ibm.com/developerworks/jp/linux/library/l-systemtap/
↑より
Kprobe はアーキテクチャーに特化されており、プローブ対象の命令の先頭バイトにブレークポイント命令を挿入します。ブレークポイント命令にヒットするとプローブ固有のハンドラーが実行され、それが完了すると本来の命令の実行が (ブレークポイントから) 再開され、実行が継続されます。
Kretprobe の場合は多少異なり、呼び出された関数から戻ってきた時点で動作します。関数には複数のリターン・ポイントがある場合もあるため、複雑なことのように思えますが、Kretprobe が実際に使用するのはトランポリン (trampoline) という単純な手法です。この手法では、関数のすべてのリターン・ポイントを計測するのではなく (これでは、すべての事例をキャッチできません)、わずかな量のコードを関数の入り口に追加します。このコードはスタックのリターン・アドレスをトランポリン・アドレス、つまり Kretprobe のアドレスに置き換えます。そのため関数の実行が終了すると、呼び出し側に制御が返される代わりに、Kretprobe が呼び出されます。そして呼び出された Kretprobe がその機能を実行した後、実際に関数を呼び出した側に制御を返すという仕組みです。

5 つの動作フェーズ

開始
↓
スクリプトを解析ツリーに変換 (pass 1)
↓
シンボル情報を使用してシンボルを解決(pass 2)
↓
解析ツリーを C ソースに変換(pass 3)
tapset スクリプト (SystemTap で定義された便利な機能を集めたライブラリー) も使用
↓
カーネル・モジュールの作成(pass 4)
↓
staprun と stapio
カーネルへのモジュールのインストールを管理し、その出力を stdout にルーティングします (pass 5)
↓
終了
(シェルで Ctrl-C が押された場合や、スクリプトが終了した場合は、クリーンアップ・プロセスによってモジュールがアンロードされ、その結果、関連するすべてのユーティリティーが終了)

Systemtap使ってみた

カーネルスタックの計測

もっとも頻繁にカーネルスタックの値が同じである回数を知ることができ、頻繁に実行されているカーネルスタックの中身は何かがわかる

kernelstack.stp

global s;

probe timer.profile{
    # 現在のカーネルスタックの16 進バックトレース
    if (execname() == "java")
        s[backtrace()] <<< 1
}
probe end{
    foreach(i in s+){
        # スタック番地からカーネルスタックの中身を出力
        print_stack(i)
        printf("\n\t%d\n",@count(s[i]))
    }
}

結果

 0xffffffff811b551a : __d_lookup+0x9a/0x150 [kernel]

        1
 0xffffffff810198db : syscall_trace_enter+0x16b/0x1e0 [kernel]

        2
 0xffffffff8111a6bf : prof_syscall_enter+0x1bf/0x270 [kernel]

        2
 0xffffffff810682ff : finish_task_switch+0x4f/0xf0 [kernel]

        11
 0xffffffffa12a407c : 0xffffffffa12a407c [stap_827021213c17f52ed8777c332d91e694_6260+0x807c/0x0]
 0xffffffffa12a57d3 : 0xffffffffa12a57d3 [stap_827021213c17f52ed8777c332d91e694_6260+0x97d3/0x0]
 0xffffffffa12a700e : 0xffffffffa12a700e [stap_827021213c17f52ed8777c332d91e694_6260+0xb00e/0x0]
 0xffffffff810b0d49 : profile_tick+0x99/0xa0 [kernel]
 0xffffffff810b8a50 : tick_sched_timer+0x70/0xc0 [kernel]
 0xffffffff810ab12e : __run_hrtimer+0x8e/0x1d0 [kernel]
 0xffffffff810ab4ce : hrtimer_interrupt+0xee/0x270 [kernel]
 0xffffffff8103879d : local_apic_timer_interrupt+0x3d/0x70 [kernel]
 0xffffffff81552f55 : smp_apic_timer_interrupt+0x45/0x60 [kernel]
 0xffffffff8100bc13 : apic_timer_interrupt+0x13/0x20 [kernel]
 0xcf9b000000ffff : 0xcf9b000000ffff

        128

カーネル関数のコールグラフ

kernelfunction-callgraph.stp

probe module("ext4").function("*").call
{
  if (execname() == "java")
  printf ("%s -> %s\n", thread_indent(1), probefunc())
}
probe module("ext4").function("*").return
{
  if (execname() == "java")
  printf ("%s <- %s\n", thread_indent(-1), probefunc())
}

結果

     0 java(3926): -> ext4_readdir
    10 java(3926):  -> free_rb_tree_fname
    15 java(3926):  <- ext4_readdir
    18 java(3926):  -> ext4_htree_fill_tree
    25 java(3926):   -> htree_dirblock_to_tree
    31 java(3926):    -> ext4_bread
    37 java(3926):     -> ext4_getblk
    43 java(3926):      -> ext4_get_blocks
    50 java(3926):       -> ext4_ext_get_blocks
    56 java(3926):       <- ext4_get_blocks
    60 java(3926):       -> ext4_data_block_valid
    67 java(3926):       <- ext4_get_blocks
    68 java(3926):      <- ext4_getblk
    74 java(3926):     <- ext4_bread
    76 java(3926):    <- htree_dirblock_to_tree
    79 java(3926):    -> ext4_check_dir_entry
    84 java(3926):    <- htree_dirblock_to_tree
    88 java(3926):    -> ext4fs_dirhash
    96 java(3926):     -> str2hashbuf_signed
   101 java(3926):     <- ext4fs_dirhash
   103 java(3926):    <- htree_dirblock_to_tree
   105 java(3926):    -> ext4_htree_store_dirent
   111 java(3926):    <- htree_dirblock_to_tree
   113 java(3926):    -> ext4_check_dir_entry
   115 java(3926):    <- htree_dirblock_to_tree
   117 java(3926):    -> ext4fs_dirhash
   119 java(3926):     -> str2hashbuf_signed
   121 java(3926):     <- ext4fs_dirhash
   122 java(3926):    <- htree_dirblock_to_tree
   124 java(3926):    -> ext4_htree_store_dirent
   127 java(3926):    <- htree_dirblock_to_tree
   128 java(3926):   <- ext4_htree_fill_tree
   130 java(3926):  <- ext4_readdir
   132 java(3926):  -> call_filldir
   137 java(3926):  <- ext4_readdir
   139 java(3926):  -> call_filldir
   141 java(3926):  <- ext4_readdir
   142 java(3926): <- vfs_readdir

メモ

ユーザー空間

カーネル3.5以上だとユーザー空間もプローブできる。

関数でグローバルな変数へのアクセス

When a target variable is not local to the probe point, like a global external variable or a file local static variable defined in another file then it can be referenced through

“@var("変数名@src/file.c")”.

構造体へのアクセス

@var("変数名@src/file.c")->構造体メンバ

これで外部変数に入っている構造体のメンバにもアクセスできる

キャスティング

コードの中ではvoidのポインタかも、型情報は使えないかも
プローブハンドラの中では型情報は使えるが、stapの中で自分で作成した関数では使えない。
その関数の中では。ポインタはlong型を使うようになっている

よって

@cast() operator

第一引数
- ポインター
第二引数
- キャストしたい型
第三引数(オプション４)
- キャストしたい型が定義してあるファイル

function task_state:long (task:long)
{
 return @cast(task, "task_struct", "kernel<linux/sched.h>")->state
}

これでtask_struct task->stateでアクセスできる

まとめ

カーネルスタックの値を動的に見れたのは初めてだった
本格的に使っていないのでなんともですが、perfコマンドやOSのコマンドである程度調査はできそう。
SystemTapを使いながら内部の挙動に詳しくなる

SystemTap使ってみた

概要

インストール

必要なもの

`kernel-devel`とは

`kernel-debuginfo`とは

インストールの確認

SystemTapの実行

SystemTap書式

プローブポイント一覧

SystemTapの仕組み

5 つの動作フェーズ

Systemtap使ってみた

カーネルスタックの計測

カーネル関数のコールグラフ

メモ

ユーザー空間

関数でグローバルな変数へのアクセス

構造体へのアクセス

キャスティング

@cast() operator

まとめ

参考

SystemTap使ってみた

概要

インストール

必要なもの

kernel-develとは

kernel-debuginfoとは

インストールの確認

SystemTapの実行

SystemTap書式

プローブポイント一覧

SystemTapの仕組み

5 つの動作フェーズ

Systemtap使ってみた

カーネルスタックの計測

カーネル関数のコールグラフ

メモ

ユーザー空間

関数でグローバルな変数へのアクセス

構造体へのアクセス

キャスティング

@cast() operator

まとめ

参考

`kernel-devel`とは

`kernel-debuginfo`とは