Main | Chime »

DTrace for IO provider

Sun Solution CenterでのBenchmarkingでDTraceについて聞かれることが増えてきたので、簡単に解析ができる内容やtipsなどをまとめみます。

私がお客様に、DTraceを話す際には、DTrace Tool Kitをお客様に勧めておりますが、今回は、DTrace one linerで簡単にI/O解析をおこなってみます。なお、さらに深く知りたい場合は、Solaris performance metricを参照してください。いかに、DTraceが簡単に、かつ詳細に利用できるのかが、お分かりになると思います。 Performance測定をする際(特にOracleなど)に、I/Oを意識します。DTraceを利用すると、trussやiostat以上に詳細に分析できることがわかると思います。 DTraceを利用することによって、次にあるような例を容易に、解析できます。
1). 現在、I/Oを発行しているProcess execは何か?
2). そのProcessは、read or write?
3). そのプロセスのI/O sizeは?
4). そのI/Oプロセスのfile pathは、何か?
5). そのI/Oが発行しているシステムコールは何か?
 これらの例題を解くのに、DTraceは非常に有力です。Solaris10以前の機能ですと、これらの問題を解くのに、TNFやtrussなどを使ったかと思いますが、DTraceだとたった1行でこれらの問題を解決することができます。 まずは、どんなI/O probeが提供しているかをみてみる。確認方法は、以下のとおりです。

 [kato@d-ctyo03-53-23]$ dtrace -l -P io
   ID   PROVIDER            MODULE                          FUNCTION NAME
  513         io           genunix                           biodone done
  514         io           genunix                           biowait wait-done
  515         io           genunix                           biowait wait-start
  526         io           genunix                    default_physio start
  527         io           genunix                     bdev_strategy start
  528         io           genunix                           aphysio start
 1317         io               nfs                          nfs4_bio done
 1318         io               nfs                          nfs3_bio done
 1319         io               nfs                           nfs_bio done
 1320         io               nfs                          nfs4_bio start
 1321         io               nfs                          nfs3_bio start
 1322         io               nfs                           nfs_bio start

DTraceは、provider:module:function:nameで構成されています。

1)それでは、I/Oを実行しているプロセスをexecしているプロセスを出力してみましょう。

[kato@d-ctyo03 53-23]$ dtrace -n ‘io:::start{printf(“%s\\n”,execname)}‘
dtrace: description ‘io:::start‘ matched 6 probes
CPU ID FUNCTION:NAME
0 524 bdev_strategy:start prstat

0 524 bdev_strategy:start fsflush

0 524 bdev_strategy:start sched

0 524 bdev_strategy:start sched

0 524 bdev_strategy:start sched

0 524 bdev_strategy:start sched

0 524 bdev_strategy:start sched
実行結果をみると、prstat, fsflush, schedが走っていることがわかります。しかしながら、Read or writeしているのかがいまいちわかりません、、
2)それでは、次に、Read or Writeしているかをみましょう。
[kato@d-ctyo03 53-23]$
dtrace -n ‘io:::start{printf(“%s %s %d %s\\n“,execname,args[0]->b_flags&B_READ?"R":“W”}‘
dtrace: description ‘io:::start‘ matched 6 probes

0 524 bdev_strategy:start sched W

0 524 bdev_strategy:start sched W

0 524 bdev_strategy:start sched W

0 524 bdev_strategy:start sched W

0 524 bdev_strategy:start sched W
schedがwriteしていることがわかります。
3)それでは、次に、そのI/O sizeを出力してみましょう。
I/O sizeの確認
[kato@d-ctyo03 53-23]$ dtrace -n ‘io:::start{printf(“%s %s %d,%s\\n“,execname,args[0]->b_flags&B_READ?"R":“W”,args[0]->b_bcount)}‘

dtrace: description ‘io:::start‘ matched 6 probes
CPU ID FUNCTION:NAME
0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 4096

0 524 bdev_strategy:start prstat R 8192
IOSizeが8Kもしくは、4Kで書かれていることがわかる。しかし、そのI/Oがどのpathにいっているのかわからないので、次のDTraceで確認することができる。
4)それでは、次にfilepathを出力してみましょう。
filepathの確認
[kato@d-ctyo03 53-23]$ dtrace -n ‘io:::start{printf(“%s %s %d %s\\n“,execname,args[0]->b_flags&B_READ?"R":“W”,args[0]->b_bcount,args[2]->fi_pathn
ame)}‘
dtrace: description ‘io:::start‘ matched 6 probes
CPU ID FUNCTION:NAME
0 524 bdev_strategy:start prstat R 4096 /usr/bin/amd64
/prstat

0 524 bdev_strategy:start fsflush W 2048

prstatは、Read 4Kで/usrbin/amd64をreadしていることがわかります。
5)最後にprstatのsyscallをおってみましょう。
 [kato@d-ctyo03 53-23]$ dtrace -n ‘syscall:::entry/execname==“prstat”/{@[execname,probefunc]=count();}‘
dtrace: description ‘syscall:::entry‘ matched 231 probes
\^C

prstat pollsys
1
prstat getloadavg
1
prstat write
2
prstat lseek
2
prstat getdents
2
prstat doorfs
42
prstat pread
114
preadしていることがわかる。
さらに、深く知りたい場合は、fbt providerを使うとさらに細かく分析することができます。
また、Performance testなどを利用する際には、profile providerを利用すると、分析しやすくなります。
1行で、iostatなどよりも細かく分析できることがわかりましたでしょうか。
次回は、実際のアプリケーションを利用した簡単な事例を紹介します。

Reference
 b_flagの詳細は、/usr/lib/dtrace/io.dを参照してください。
b_flagsでとってこれる値(I/O provider)
inline int B_BUSY = 0×0001;

#pragma D binding “1.0“ B_BUSY
inline int B_DONE = 0×0002;

#pragma D binding “1.0“ B_DONE
inline int B_ERROR = 0×0004;

#pragma D binding “1.0“ B_ERROR
inline int B_PAGEIO = 0×0010;

#pragma D binding “1.0“ B_PAGEIO
inline int B_PHYS = 0×0020;

#pragma D binding “1.0“ B_PHYS
inline int B_READ = 0×0040;

#pragma D binding “1.0“ B_READ
inline int B_WRITE = 0×0100;

#pragma D binding “1.0“ B_WRITE
inline int B_ASYNC = 0×000400;

#pragma D binding “1.0” B_ASYNC

このProviderを利用しやすいようにTranslateしています。


Main | Chime »
Comments:

こんにちは、飛場です。 プローブという単語でずーっと気になっていたのですが、 このIOに関してのスレッドを見て思い出したのですが、 DTraceってprex + tnfxtract + tnfdump の組み合わせをいっぺんに出来て、 尚且つ、スクリプトが用意されているわけですね。

Posted by 飛場 on April 10, 2007 at 05:21 AM JST #

Post a Comment:
  • HTML Syntax: NOT allowed
About

This blog is talked about OpenSolaris Community Activity and Bencmarking Test, which are my job.

Search

Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today