空色ブログ

anything about Solaris


« building MySQL from... | メイン | libkstat の使い方 »
木曜日 7 03, 2008

cat /dev/urandom

はじめに

  • トラブルシュートや技術調査、新機能のデモンストレーションを行っていると、何でも良いから CPU 負荷を発生させたいというシチュエーションに出くわす事があります。例えば Solaris のコマンドの挙動を調べたい時、いつ何回実行しても必ず 1 CPU を振り切ってくれて、必要な時間だけ動かし続ける事が出来て、幾つ同時に走らせてもコンテンションが発生せず、インストールもコンパイルも必要なく、マルチスレッド化されていなくて構わないので、頭を使わず、殆ど手も動かさず、簡単に実行出来る方法があると便利です。そんな時、私は /dev/urandom を使用する事が多いです。以下、実際に /dev/urandom を使用して各種コマンドの挙動を試した結果を載せましたので、ご覧下さい。なお /dev/urandom は Solaris 以外でも殆どの OS に存在しています。出来れば Solaris を導入して試して頂きたいですが、Mac OS X や CentOS でも似たような事をする事が可能です。

注意

  • お手元で試される場合は必ず 2 コア以上のシステムを使用して下さい。Solaris のスケジューラは十分賢いので 1 コアでも最悪の事態には至りませんが、お薦めは出来ません。
  • プロダクションシステムや自分が管理していないマシンでは絶対に実行しないで下さい

/dev/urandom の使い方

  • 勿論、本来の使い方（乱数生成機）とは異なりますが... 
    •  % cat /dev/urandom > /dev/null &
  • 本来の /dev/urandom の使い方は "man -s 7D urandom" をご覧下さい
  • & を付けるとバックグラウンドで動きますので、停止させる時は fg でフォアグラウンドに移動させてから Ctrl-C を入力します

Solaris のコマンドの挙動を確認する

  • /dev/urandom を cat した状態で Solaris の各種コマンドがどのような反応を示すか見てみます

テスト環境

  • Dual Core AMD Opteron Model 875 が 4 つ搭載されたマシンを使用しています 
    •  # prtconf -Dvv | grep Opteron
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
                     value='Dual Core AMD Opteron(tm) Processor 875'
  • psradm コマンドを使用してコアを半分停止してありますので、4 コアのマシンと同等です
    • コアは独立した CPU として表示されます 
      •  # psradm -f 4-7
 # psrinfo
 0       on-line   since 03/06/2008 17:33:23
 1       on-line   since 03/06/2008 17:33:29
 2       on-line   since 03/06/2008 17:33:31
 3       on-line   since 03/06/2008 17:33:33
 4       off-line  since 07/02/2008 14:49:35
 5       off-line  since 07/02/2008 14:49:35
 6       off-line  since 07/02/2008 14:49:35
 7       off-line  since 07/02/2008 14:49:35
  • メモリは 24GB です 
    •  # prtconf -Dvv | grep 'Memory size'
 Memory size: 24512 Megabytes

事前準備

  • 前述の通り /dev/urandom を cat しておくだけ準備は完了です 
    •  % cat /dev/urandom > /dev/null &

mpstat

  • まずは mpstat を試してみます 
    •  # mpstat 1
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    1   0   11   313  206   57    0    0    0    0    19    0   0   0 100
   1    0   0   42    25    0   43    0    0    0    0    22    0   0   0 100
   2    1   0    0    16    4    4    0    0    0    0    37    0   0   0 100
   3    0   0    0    11    0    3    0    0    0    0    27    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   379  207   57    0    0    2    0     0    0   1   0  99
   1    0   0  485    38    9   55    0    0    0    0     0    0   0   0 100
   2    0   0    0    82    3    0    7    0    0    0 40398    0 100   0   0
   3   11   0    0    74    0    8    0    0    0    0    96    1   0   0  99
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   315  213   50    0    1    1    0     0    0   0   0 100
   1    0   0    0    38   12   50    0    0    1    0     0    0   0   0 100
   2    0   0    0    16    6    3    8    0    1    0 39645    1  99   0   0
   3    0   0    0     5    0    8    0    0    0    0    95    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   319  213   59    0    0    1    0     0    0   0   0 100
   1    0   0    0    37   11   50    0    0    1    0     0    0   0   0 100
   2    0   0    0    16    6    0    7    0    0    0 40440    0 100   0   0
   3    1   0    0    10    0   18    0    0    0    0   101    0   0   0 100
 ^C
  • mpstat は CPU 毎の統計情報を見るコマンドです
  • 最初の行はヘッダで、以降 1 CPU につき 1 行ずつ統計情報が出力されます
  • "mpstat 1" で 1 秒間隔の統計情報を出力しています
  • 1 番最初の出力は不正確な値ですので無視して下さい
  • 2-3 秒目の出力を見ると CPU 2 番で idl のカラムが 0 になっています。これは "cat /dev/urandom" が 1 CPU を使い切ってアイドル時間が 0 である事を示しています。また、idl の代わりに sys が 100 になっていますが /dev/urandom はカーネル空間で動いている為、使用した CPU サイクルは sys にカウントされます。syscl のカラムはシステムコールの回数を示していますが、この値も CPU 2 番で大きくなっています。
  • "cat /dev/random" を実行していない場合の mpstat の出力も載せておきますので、上記と比較してみて下さい 
    •  # mpstat 1
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    1   0    1   313  206   57    0    0    0    0    19    0   0   0 100
   1    0   0   42    23    0   43    0    0    0    0    22    0   0   0 100
   2    1   0    0    15    4    4    0    0    0    0    36    0   0   0 100
   3    0   0    0     9    0    3    0    0    0    0    27    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   319  213  105    0    1    1    0     0    0   0   0 100
   1    0   0    0     5    1    6    0    0    1    0     0    0   0   0 100
   2   11   0    0     7    2    6    0    0    1    0    98    0   0   0 100
   3    0   0    0     2    0    2    0    0    0    0     0    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   330  228   95    0    0    2    0     0    0   0   0 100
   1    0   0    0    11    2   16    0    0    0    0     2    0   0   0 100
   2    0   0    0    10    4    6    0    0    0    0    95    0   0   0 100
   3    0   0    0     5    0    8    0    0    0    0     1    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   321  219   92    0    0    1    0     0    0   0   0 100
   1    0   0    0     9    3    8    0    0    0    0     1    0   0   0 100
   2    0   0    0    12    5    6    0    0    0    0    95    0   0   0 100
   3    0   0    0     4    1    2    0    0    0    0     0    0   0   0 100
 ^C

vmstat

  • 次に vmstat を見てみます。 
    •  # vmstat 1                      
  kthr      memory            page            disk          faults      cpu
  r b w   swap  free  re  mf pi po fr de sr f0 s0 s1 s2   in   sy   cs us sy id
  0 0 0 33477380 23997964 0 1 0  0  0  0  0 -0 -0  0  0  364  104  107  0  0 100
  0 0 0 33388680 23930924 16 31 0 0 0  0  0  0  0  0  0  349 40216 104  0 25 75
  0 0 0 33388680 23930944 6 6 0  0  0  0  0  0  0  0  0  352 40175 109  0 25 75
  0 0 0 33388680 23930944 6 6 0  0  0  0  0  0  0  0  0  532 40045 117  0 25 75
 ^C
  • "cat /dev/urandom" を動かしていない場合は以下の出力になります 
    •  # vmstat 1
  kthr      memory            page            disk          faults      cpu
  r b w   swap  free  re  mf pi po fr de sr f0 s0 s1 s2   in   sy   cs us sy id
  0 0 0 33477380 23997964 0 1 0  0  0  0  0 -0 -0  0  0  364  105  107  0  0 100
  0 0 0 33388864 23931072 16 31 0 0 0  0  0  0  0  0  0  363  132  112  0  0 100
  0 0 0 33388864 23931092 6 6 0  0  0  0  0  0  0  0  0  360  117  109  0  0 100
  0 0 0 33388864 23931092 6 6 0  0  0  0  0  0  0  0  0  360  118  112  0  0 100
 ^C
  • vmstat はシステム全体の統計を見渡すのに便利なコマンドです
  • mpstat の時と同じ様に sys の値が上がっています。vmstat の sys は全 CPU の合計になっており、4 CPU のマシンで 1 CPU だけを使い切っている場合は 100 * 1/4 = 25 になります。また sy のカラムがシステムコールの回数ですが、こちらも数字が上がっています。

prstat

  • 続いて prstat コマンドの挙動を見てみます 
    •  # prstat -n 5 1 3 > /tmp/prstat.log    
 # cat /tmp/prstat.log 
    PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP       
   5898 root     1048K  692K cpu0     0    5   0:02:10  25% cat/1
   5902 root     2992K 2500K cpu2    59    0   0:00:00 0.0% prstat/1
    323 root     1740K  940K sleep   59    0   0:00:00 0.0% smcboot/1
      9 root       11M 9772K sleep   59    0   0:01:15 0.0% svc.configd/17
      7 root       12M   11M sleep   59    0   0:00:31 0.0% svc.startd/16
 Total: 43 processes, 181 lwps, load averages: 0.88, 0.35, 0.30
    PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP       
   5898 root     1048K  692K cpu0     0    5   0:02:11  25% cat/1
   5902 root     3332K 2712K cpu2    59    0   0:00:00 0.0% prstat/1
    323 root     1740K  940K sleep   59    0   0:00:00 0.0% smcboot/1
      9 root       11M 9772K sleep   59    0   0:01:15 0.0% svc.configd/17
      7 root       12M   11M sleep   59    0   0:00:31 0.0% svc.startd/16
 Total: 43 processes, 181 lwps, load averages: 0.88, 0.36, 0.30
    PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP       
   5898 root     1048K  692K cpu0     0    5   0:02:12  25% cat/1
   5902 root     3332K 2712K cpu2    59    0   0:00:00 0.0% prstat/1
    323 root     1740K  940K sleep   59    0   0:00:00 0.0% smcboot/1
      9 root       11M 9772K sleep   59    0   0:01:15 0.0% svc.configd/17
      7 root       12M   11M sleep   59    0   0:00:31 0.0% svc.startd/16
 Total: 43 processes, 181 lwps, load averages: 0.88, 0.36, 0.31
  • prstat コマンドはプロセス毎のか同状況を一覧するのに便利なコマンドです
  • "prstat -n 5 1 3" で毎回 5 行出力、1 秒間隔で、3 秒間統計情報を取得しています
  • 1 行目はヘッダです。2 行目以降、プロセス毎に 1 行ずつ統計情報を出力しています。
  • cat のプロセスが CPU を 25% 使用している事が分かります。vmstat と同様、全 CPU を合わせて 100% になりますので、25% は 4 CPU の内 1 CPU 相当を使っている事になります。また STATE のカラムでプロセスがどの CPU 上で動いているか分かります。上の出力例では cat のプロセスは CPU 0 番上で動いています。PRI はプロセスのプライオリティです。cat は CPU を既に沢山使用しているため、優先順位が他のプロセスに比べて低くなっています。
  • prstat は Solaris 固有のコマンドです。Mac OS X や *BSD, Linux では top コマンドで代用して下さい。

pgrep

  • ここで一旦寄り道をして pgrep コマンドに付いて説明します
  • 普段プロセスの ID を調べたい時には ps コマンドを使用する事が多いと思います 
    •  # ps -ef | grep 'cat /dev/urandom'
     root  5898  5765  25 16:25:15 pts/1      23:15 cat /dev/urandom
     root  5957  5765   0 16:48:30 pts/1       0:00 grep cat /dev/urandom
  • -o オプションで args を指定すると引数付きのコマンド名を出力します 
    •  # ps -eo 'pid args' | grep 'cat /dev/urandom'
  5898 cat /dev/urandom
  5981 grep cat /dev/urandom
  • プロセス ID は pgrep コマンドを使用して取得する事も出来ます
    • -f オプションで引数付きのコマンド名を対象に grep 出来ます 
      •  # pgrep -f 'cat /dev/urandom' 
 5898
    • -l オプションで引数付きのコマンド名を表示します 
      •  # pgrep -lf 'cat /dev/urandom'
  5898 cat /dev/urandom
  • pgrep を使用するとコマンドの引数にプロセス ID を渡す時に便利です 
    •  # pflags `pgrep -f 'cat /dev/urandom'`
 5898:	cat /dev/urandom
 	data model = _ILP32  flags = MSACCT|MSFORK
  /1:	flags = 0
 # pfiles `pgrep -f 'cat /dev/urandom'`           
 5898:	cat /dev/urandom
   Current rlimit: 65536 file descriptors
    0: S_IFCHR mode:0620 dev:274,0 ino:12582918 uid:0 gid:7 rdev:24,1
       O_RDWR
       /devices/pseudo/pts@0:1
    1: S_IFCHR mode:0666 dev:274,0 ino:6815752 uid:0 gid:3 rdev:13,2
       O_WRONLY|O_CREAT|O_TRUNC|O_NOCTTY|O_LARGEFILE
       /devices/pseudo/mm@0:null
    2: S_IFCHR mode:0620 dev:274,0 ino:12582918 uid:0 gid:7 rdev:24,1
       O_RDWR
       /devices/pseudo/pts@0:1
    3: S_IFCHR mode:0644 dev:274,0 ino:78118918 uid:0 gid:3 rdev:149,1
       O_RDONLY|O_LARGEFILE
       /devices/pseudo/random@0:urandom

pstop, prun

  • pstop はプロセスを一時的に停止させるコマンドです
  • prun は pstop で停止させたプロセスを再開するコマンドです 
    •  # vmstat 1 3                        
  kthr      memory            page            disk          faults      cpu
  r b w   swap  free  re  mf pi po fr de sr f0 s0 s1 s2   in   sy   cs us sy id
  0 0 0 33477344 23997940 0 1 0  0  0  0  0 -0 -0  0  0  364  116  107  0  0 100
  0 0 0 33388772 23930916 16 31 0 0 0  0  0  0  0  0  0  562 40127 105  0 25 75
  0 0 0 33388772 23930936 6 6 0  0  0  0  0  0  0  0  0  389 40302 114  0 25 75
 # pstop `pgrep -f 'cat /dev/urandom'`
 # vmstat 1 3                         
  kthr      memory            page            disk          faults      cpu
  r b w   swap  free  re  mf pi po fr de sr f0 s0 s1 s2   in   sy   cs us sy id
  0 0 0 33477344 23997940 0 1 0  0  0  0  0 -0 -0  0  0  364  116  107  0  0 100
  0 0 0 33388772 23930916 16 31 0 0 0  0  0  0  0  0  0  363  131  119  0  0 100
  0 0 0 33388772 23930936 6 6 0  0  0  0  0  0  0  0  0  362  113  111  0  0 100
 # prun `pgrep -f 'cat /dev/urandom'` 
 # vmstat 1 3                        
  kthr      memory            page            disk          faults      cpu
  r b w   swap  free  re  mf pi po fr de sr f0 s0 s1 s2   in   sy   cs us sy id
  0 0 0 33477344 23997940 0 1 0  0  0  0  0 -0 -0  0  0  364  116  107  0  0 100
  0 0 0 33388772 23930916 16 31 0 0 0  0  0  0  0  0  0  358 39876 125  0 25 75
  0 0 0 33388772 23930936 6 6 0  0  0  0  0  0  0  0  0  334 39940 106  0 25 75
  • pstop でプロセスを停止させると CPU の使用率が 0 になる事が分かります
  • 引数の PID の指定には前述の pgrep コマンドを使用しました
  • "cat /dev/urandom" を使用する事で pstop, prun の動きを簡単に試す事が出来ました

truss

  • truss は（主に）システムコールの追跡をする為のコマンドです。トラブルシュートやベンチマークで非常に役に立ちます。 
    •  # truss -E -vall -p `pgrep -f 'cat /dev/urandom'`
  0.0000	write(1, "EAEE83 hE280 nCFD5AFCD D".., 1040)	= 1040
  0.0000	read(3, " 1 Q1490FA 0 XC8FE f ^15".., 8192)	= 1040
  0.0000	write(1, " 1 Q1490FA 0 XC8FE f ^15".., 1040)	= 1040
  0.0000	read(3, "92D0 l0E9CD6 {B2 Z G Q97".., 8192)	= 1040
  0.0000	write(1, "92D0 l0E9CD6 {B2 Z G Q97".., 1040)	= 1040
  0.0000	read(3, "BD82 $BD a z97A9 v95B8 X".., 8192)	= 1040
  0.0000	write(1, "BD82 $BD a z97A9 v95B8 X".., 1040)	= 1040
  • read(2) した物をそのまま write(2) している事が分かります
  • -E オプションを付けていますので一番左のカラムはシステムコールの実行にかかった時間です
  • read(2) の第 1 引数はファイルディスクリプタ番号で、前述の pfiles の結果から /dev/random である事が分かります。第 3 引数は読み込むサイズです。一番右のカラムは返り値で、実際に何 bytes 読み込めたかを示しています。
  • write(2) の第 1 引数は標準出力です。このコマンドでは /dev/null にリダイレクトされていますので、結果は単純に捨てられています。第 3 引数は書き出したいサイズで、一番右のカラムが実際に書き出されたサイズです。
  • read(2) で /dev/random から 1040 bytes 読み込んで、それをそのまま標準出力に書き出しているだけなのが分かります

truss -c

  • もうひとつ truss の便利な使い方に -c オプションがあります 
    •  # truss -c -p `pgrep -f 'cat /dev/urandom'`      
 ^C
 syscall               seconds   calls  errors
 read                    2.730   50584
 write                    .256   50585
                      --------  ------   ----
 sys totals:             2.986  101169      0
 usr time:                .098
 elapsed:                5.740
  • -c を付けるとシステムコールの累積時間と累積回数を見る事が出来ます。write(2) と read(2) はほぼ同じ回数ですが、比較してみると read(2) にかなり時間がかかっている事が分かります。
  • truss は Solaris 固有のコマンドです。Mac OS X には DTrace 由来の dtruss コマンドがありますが、まだ機能は限定的です。他のプラットフォームでは strace や ktrace コマンドがある程度似たような機能を提供しています。

truss -u

  • truss はシステムコールを追跡すると書きましたが、ユーザレベルの関数コールを追跡する事も可能です 
    •  # truss -E -u:: -p `pgrep -f 'cat /dev/urandom'`
 /1@1:    0.0000 -> libc:write(0x1, 0x80621b8, 0x410)
 /1@1:    0.0000   -> libc:_save_nv_regs(0xfeeb2c10)
 /1@1:    0.0000   <- libc:_save_nv_regs() = 0xfeeb2c10
 /1@1:    0.0001   -> libc:_write(0x1, 0x80621b8, 0x410)
 /1:      0.0000 write(1, "CF DFFD0F1E5 _9F19 E mCB".., 1040)    = 1040
 /1@1:    0.0000   <- libc:_write() = 1040
 /1@1:    0.0000 <- libc:write() = 1040
 /1@1:    0.0000 -> libc:read(0x3, 0x80621b8, 0x2000)
 /1@1:    0.0001   -> libc:_save_nv_regs(0xfeeb2c10)
 /1@1:    0.0001   <- libc:_save_nv_regs() = 0xfeeb2c10
 /1@1:    0.0001   -> libc:_read(0x3, 0x80621b8, 0x2000)
 /1:      0.0000 read(3, " FC3 _B0 : kF5B38A07 = e".., 8192)     = 1040
 /1@1:    0.0000   <- libc:_read() = 1040
 /1@1:    0.0000 <- libc:read() = 1040
 /1@1:    0.0000 -> libc:write(0x1, 0x80621b8, 0x410)
 /1@1:    0.0001   -> libc:_save_nv_regs(0xfeeb2c10)
 /1@1:    0.0001   <- libc:_save_nv_regs() = 0xfeeb2c10
 /1@1:    0.0001   -> libc:_write(0x1, 0x80621b8, 0x410)
 /1:      0.0000 write(1, " FC3 _B0 : kF5B38A07 = e".., 1040)    = 1040
 /1@1:    0.0000   <- libc:_write() = 1040
 /1@1:    0.0000 <- libc:write() = 1040
 /1@1:    0.0000 -> libc:read(0x3, 0x80621b8, 0x2000)
 /1@1:    0.0001   -> libc:_save_nv_regs(0xfeeb2c10)
 /1@1:    0.0001   <- libc:_save_nv_regs() = 0xfeeb2c10
 /1@1:    0.0001   -> libc:_read(0x3, 0x80621b8, 0x2000)
  • -u:: オプションを付けると関数コールのフローを表示します
  • システムコールがどの関数からどのようなパスで呼び出されているかを観察するのに便利です

cpustat

  • cpustat は CPU 内のカウンタを出力するコマンドです 
    •  # cpustat -c IC_miss 1                 
    time cpu event      pic0 
   1.004   1  tick       193 
   1.004   3  tick       816 
   1.004   2  tick       241 
   1.004   0  tick      8856 
   2.004   1  tick       343 
   2.004   3  tick       528 
   2.004   2  tick       278 
   2.004   0  tick      8584 
   3.004   1  tick       188 
   3.004   3  tick       175 
   3.004   2  tick       182 
   3.004   0  tick      8280 
   4.004   3  tick       113 
   4.004   1  tick       170 
   4.004   2  tick       166 
   4.004   0  tick      8275 
   5.004   3  tick       107 
   5.004   1  tick       158 
   5.004   2  tick       330 
   5.004   0  tick      8282 
 ^C
 # mpstat 1 3
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    1   0   11   313  206   57    0    0    0    0    45    0   0   0 100
   1    0   0   42    25    0   43    0    0    0    0    25    0   0   0 100
   2    1   0    0    17    4    4    0    0    0    0    38    0   0   0 100
   3    0   0    0    11    0    3    0    0    0    0    27    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   313  210    0    7    0    0    0 39747    0 100   0   0
   1    0   0    0    60   10   99    0    2    0    0     0    0   0   0 100
   2    8   0    0    14    6   10    0    0    0    0    98    0   0   0 100
   3    0   0    0     3    0    4    0    0    0    0     0    0   0   0 100
 CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
   0    0   0    0   310  208    0    7    0    0    0 39725    1  99   0   0
   1    0   0    0    56   10   91    0    0    0    0     0    0   0   0 100
   2    1   0    0    14    6   10    0    0    0    0    95    0   0   0 100
   3    0   0    0     1    0    0    0    0    0    0     0    0   0   0 100
  • IC_miss は命令キャッシュミスです。"cat /dev/urandom" のプロセスが動いている CPU 0 番で命令キャッシュミスが多く発生している事が見て取れます。
  • cpustat はマイクロベンチマークで威力を発揮します

cputrack

  • cpustat とほぼ同じ機能を持ったコマンドに cputrack があります。こちらはプロセスを指定して実行する事が出来ます。 
    •  # cpustat -c IC_miss -p `pgrep -f 'cat /dev/urandom'` 1
    time cpu event      pic0 
   1.010   1  tick       221 
   1.010   3  tick        71 
   1.010   0  tick      8701 
   1.010   2  tick      5930 
   2.010   1  tick       387 
   2.010   2  tick       489 
   2.010   3  tick       407 
   2.010   0  tick      8671 
   3.010   2  tick       147 
   3.010   1  tick       209 
   3.010   3  tick       177 
   3.010   0  tick      8351 
   4.010   1  tick       353 
   4.010   2  tick       282 
   4.010   0  tick      8313 
   4.010   3  tick       178 
 ^C

kstat -p

  • 前述の mpstat や vmstat コマンドは統計情報を集計するのに kstat を使用しています。kstat はカーネルの統計情報を一元管理している仕組みで、そこに直接アクセスするコマンドも用意されています。 
    •  # kstat -p 'cpu::sys:cpu_ticks_kernel' 1 3
 cpu:0:sys:cpu_ticks_kernel	1823530
 cpu:1:sys:cpu_ticks_kernel	2645270
 cpu:2:sys:cpu_ticks_kernel	453506
 cpu:3:sys:cpu_ticks_kernel	1802559
 
 cpu:0:sys:cpu_ticks_kernel	1823630
 cpu:1:sys:cpu_ticks_kernel	2645270
 cpu:2:sys:cpu_ticks_kernel	453506
 cpu:3:sys:cpu_ticks_kernel	1802559
 
 cpu:0:sys:cpu_ticks_kernel	1823730
 cpu:1:sys:cpu_ticks_kernel	2645270
 cpu:2:sys:cpu_ticks_kernel	453506
 cpu:3:sys:cpu_ticks_kernel	1802559
  • "cat /dev/urandom" が動いている CPU 0 番の tick が 100 ずつ上がっている事が分かります

DTrace

  • 最早 DTrace は解析作業に無くてはならないツールです。必要な事がちゃんと出来てお手軽で使い勝手の良い素晴らしいツールです。 
    •  # dtrace -s /usr/demo/dtrace/libc.d -p `pgrep -f 'cat /dev/urandom'` 
 dtrace: script '/usr/demo/dtrace/libc.d' matched 2570 probes
 ^C
 
   _read                                                        143901
   _write                                                       143901
   read                                                         143901
   write                                                        143901
   _save_nv_regs                                                287802
  • 上記は DTrace のデモスクリプトから libc の関数が何回呼ばれたかを調べるスクリプトを実行した結果です。"cat /dev/urandom" などをターゲットにすれば、自作のスクリプトも簡単に動作確認する事が可能です。

まとめ

  • 以上見て頂きました通り、"cat /dev/urandom" を使って CPU 負荷を生成する事で簡単にコマンドの挙動を確認する事が出来ます。ここでご紹介したのはほんの一部ですが、他にも有効な局面は幾つかあると思います。ちょっとトリッキーな小ネタですが、皆さまのご参考になれば幸いです。

Posted at 02:12午後 7 03, 2008 by Daisuke Homma in Solaris  |  投稿されたコメント[0]

投稿されたコメント:

コメント
  • HTML文法 不許可

Today's Page Hits: 182