Hisayoshi Kato's weblog at Sun Solution Center
Sunday Dec 31, 2006
fsinfo providerの使いどころ
fsinfo providerは、確か change logによると、snv38から導入されたproviderです。
たった１行で、ファイルシステムの細かいOperationを知ることができます。ファイルシステムというと、UFS, ZFSを思い浮かべる方が多いのかなって思うんですけれど、それらのファイルシステムだけではなく、tmfs, sockfsなど、あんまり意識しないファイルシステム操作を追跡できます。
DTrace によるパフォーマンス分析では、仮説を立てることがメインです。そのために、一番大切なのは、アプリケーションを動かす際に、そのアプリケーションがどんな振る舞いをしているかを把握する必要がでるわけです。
たとえば、データベースの世界でもよくこのような話はでてくると思いますが、論理I/Oと物理I/Oです。
既存のツール iostat最近では、fsstatかな？も十分使えます。ですが、アプリケーションからみると、ある特定のアプリケーションの物理I/Oや論理I/Oをとらえることができないと私は思っています。
本題ですが、firefoxでもDTraceしてみようかなって思います。（fsinfoプロバイダを使って）あくまでも焦点は、論理I/Oです。この操作は、主にvnodeと呼ばれるファイルシステムを形成するオブジェクトに関する操作のことをいいます。(詳しくは、Solairs Internalsを読んでください。)物理I/Oに関しては、DTrace for IO providerをご覧ください。
1) dtrace -l -P fsinfo で、ファイルシステム操作のprobeを表示します。
| kato@kato-ferrari> uname -a SunOS kato-ferrari 5.11 snv_54 i86pc i386 i86pc kato@kato-ferrari> dtrace -l -P fsinfo ID PROVIDER MODULE FUNCTION NAME 4147 fsinfo genunix fop_vnevent vnevent 4148 fsinfo genunix fop_shrlock shrlock 4149 fsinfo genunix fop_getsecattr getsecattr 4150 fsinfo genunix fop_setsecattr setsecattr 4151 fsinfo genunix fop_dispose dispose ... 4189 fsinfo genunix fop_close close 4190 fsinfo genunix fop_open open |
2)とりあえず、使ってみましょう。
| kato@kato-ferrari> dtrace -n 'fsinfo:::{printf("%s",execname);}' 0 4156 fop_poll:poll gnome-terminal 0 4156 fop_poll:poll gnome-terminal .. 0 4156 fop_poll:poll gnome-terminal 0 4186 fop_ioctl:ioctl gnome-terminal 0 4156 fop_poll:poll gnome-terminal |
gnome-terminalばっかり動いています。firefoxだけ追跡したいのに、gnome-terminalのみでていて、とてもわかりにくい。 そんなときに条件式が使えます。
3)とりあえず、processわからないから、下記のように追跡してみよう。。
| kato@kato-ferrari> pgrep firefox 1219 1241 kato@kato-ferrari> ptree 1219 1219 /bin/sh /bin/firefox 1235 /bin/sh /usr/lib/firefox/run-mozilla.sh /usr/lib/firefox/firefox-bin -U 1241 /usr/lib/firefox/firefox-bin -UILocale ja -contentLocale ja 9605 <defunct> |
| kato@kato-ferrari> dtrace -n 'fsinfo:::/execname=="firefox-bin"/{printf("%s",execname);}' dtrace: description 'fsinfo:::' matched 44 probes 0 4181 fop_lookup:lookup firefox-bin 0 4181 fop_lookup:lookup firefox-bin 0 4181 fop_lookup:lookup firefox-bin 0 4181 fop_lookup:lookup firefox-bin 0 4181 fop_lookup:lookup firefox-bin 0 4181 fop_lookup:lookup firefox-bin .. 0 4162 fop_realvp:realvp firefox-bin 0 4177 fop_rename:rename firefox-bin |
4)集約集計するともっと簡単です。
| kato@kato-ferrari> dtrace -n 'fsinfo:::/execname=="firefox-bin"/{@[probefunc,probename]=count();}' dtrace: description 'fsinfo:::' matched 44 probes ^C fop_inactive inactive 1 fop_rename rename 1 fop_write write 1 fop_close close 2 fop_create create 2 fop_open open 2 fop_getsecattr getsecattr 3 fop_getpage getpage 4 fop_dispose dispose 6 fop_realvp realvp 10 fop_cmp cmp 11 fop_putpage putpage 12 fop_read read 96 fop_seek seek 96 fop_rwlock rwlock 97 fop_rwunlock rwunlock 97 fop_getattr getattr 114 fop_poll poll 137 fop_lookup lookup 156 |
5) ファイルシステム操作をみるということは、どんなファイルシステムの操作かを知る必要がありますよね。(きっと、providerの引数をとらなくてはならないんだけど。)
だけど、fsinfo providerって、マニュアルにもないし、どうに使っていいかいまいちわからない。そんなときには、ソースコードをみるとよくわります。ソースコードの１４９行目をみると、
{ "fsinfo", NULL, 0, 0, "vnode_t *", "fileinfo_t *" },
{ "fsinfo", NULL, 1, 1, "int", "int" },
っていう記述があります。これで、だいたい検討がつきます。fileinfo_tの詳細は、docsのマニュアルのi/o provierの章を参照してください。または、DTraceにて関数引数を確認する方法をみてください。
そこで下記のようにうってみよう。
|
kato@kato-ferrari> dtrace -n 'fsinfo:::/execname=="firefox-bin"/{@[probefunc,probename,args[0]->fi_fs]=count();}' kato@kato-ferrari> dtrace -n
'fsinfo:::/execname=="firefox-bin"/{@[probefunc,probename,args[0]->fi_fs,args[0]->fi_pathname]=count();}' |
下記のようなコマンドで、firefoxの振る舞いを理解し、さらに、細かい箇所を他のprobeを使って、追跡するのが大事なのです。 fsinfoプロバイダを利用して、ある特定のvnodeオペレーションの際、どんなファイルシステムでどんなオペーレーションして、どんなアプリケーションのライブラリというところまで深く追跡することが可能です。
| dtrace -n
'fsinfo:::/execname=="firefox-bin"/{@[args[0]->fi_fs,args[0]->fi_pathname,probename,probefunc,ustack(5)]=count();}'
seek fop_seek libc.so.1`lseek64+0x7 libstoragecomps.so`__1cJAsyncRead6FpnGOsFile_pvi_i_+0xf0 libstoragecomps.so`sqlite3OsRead+0x17 libstoragecomps.so`sqlite3pager_get2+0x57d libstoragecomps.so`sqlite3pager_get+0x23 47 sockfs <unknown> poll fop_poll libc.so.1`__pollsys+0x7 libc.so.1`poll+0x52 libiiimp.so.1.0.0`stream_socket_read+0x6e libiiimp.so.1.0.0`iiimf_stream_receive+0x120 libiiimcf.so.3.0.0`iiimcf_receive_message+0x2c 51 sockfs <unknown> poll fop_poll |
Posted at 11:42AM Dec 31, 2006 by katohisa in DTrace | Comments[0]
