やっぱり Sun がスキ! : Weblog やっぱり Sun がスキ!

やっぱり Sun がスキ!

http://blogs.sun.com/yappri/date/20090528 2009年 5月 28日 木曜日

Solaris Crash Analysis Tool 5.1

システムの panic 等で採取される crash dump (/var/crash 配下に格納される)ですが、この中身を覗いてみたくなったこととかありませんか?
今回、ご紹介する Solaris Crash Analysys Tool (以下 SolarisCAT)は、採取された crash dump を解析するためのツールとなり、Solaris 2.6 から Solaris 10 および OpenSolaris をサポートしています。また、採取済みの crash dump 以外にも、稼働中のシステムの情報を採取することも可能です。
(CPU アーキテクチャが異なる環境では、crash dump の解析ができませんのでご注意ください。たとえば、SPARC 上で採取されたものを x86 環境で解析することはできず、その逆も同様となります。)

Solaris CAT は、下記 URL から入手可能です。

Solaris Crash Analysis Tool 5.1
https://cds.sun.com/is-bin/INTERSHOP.enfinity/WFS/CDS-CDS_SMI-Site/en_US/-/USD/ViewProductDetail-Start?ProductRef=SCAT-5.1-G-F@CDS-CDS_SMI

パッケージ形式での配布となりますので、download 後に pkgadd コマンドでシステムにインストールすることになります。コマンド群は、/opt/SUNWscat に配置され、マニュアルは HTML ファイル (/opt/SUNWscat/docs) にて提供されます。基本的なインターフェースは、CUI (/opt/SUNWscat/bin/scat コマンド)となり対話形式にて操作することが可能です。 引数を与えずに scat を起動すると下記のメッセージが表示されます。

--
# /opt/SUNWscat/bin/scat            

  Solaris[TM] CAT 5.1b for Solaris 11 64-bit x64
    SV4842, Feb 24 2009

  Copyright 2009 Sun Microsystems, Inc. All rights reserved.
  Use is subject to license terms.

  Feedback regarding the tool should be sent to SolarisCAT_Feedback@Sun.COM
  Visit the Solaris CAT blog at http://blogs.sun.com/SolarisCAT

opening /dev/ksyms /dev/kmem ...symtab...core...done
loading core data: modules...symbols...CTF...done

files:		/dev/ksyms /dev/kmem
user:		Super-User (root:0)
release:	5.11 (64-bit)
version:	snv_114
machine:	i86pc
node name:	macbook
system type:	i86pc
hostid:		4fd7cf4c
dump_conflags:	0x10000 (DUMP_KERNEL) on /dev/zvol/dsk/rpool/dump(1G)
time in kernel:	Thu May 28 11:35:29 JST 2009
age of system:	3 hours 28 minutes 53.88 seconds
CPUs:		2 (3.72G memory)

sanity checks: settings...vmem...sysent...misc...done
SolarisCAT(live/11X)> 
--

試しに、採取された crash dump を覗いてみるには、下記のように実行します。analyze コマンドは、crash dump を自動的に解析し、原因究明への一歩を手助けしてくれる情報を出力してくれます。

--
# /opt/SUNWscat/bin/scat /var/crash/$HOSTNAME/vmcore.0

SolarisCAT(vmcore.0/11X)> analyze

core file:	/var/crash/macbook/vmcore.0
user:		Super-User (root:0)
release:	5.11 (64-bit)
version:	Apr_30_11:53_2009
machine:	i86pc
node name:	macbook
system type:	i86pc
hostid:		4fd7cf4c
dump_conflags:	0x10000 (DUMP_KERNEL) on /dev/zvol/dsk/rpool/dump(1G)
time of crash:	Thu Apr 30 19:48:38 JST 2009 (core is 27 days old)
age of system:	4 minutes 25.10 seconds
panic CPU:	1 (2 CPUs, 3.72G memory)
panic string:	BAD TRAP: type=e (#pf Page fault) rp=ffffff0008da6a30 addr=20 occurred in module "unix" due to a NULL pointer dereference


==== checking for trap information ====

CPU 1 had the panic


==== panic thread: 0xffffff01be4aa000 ==== CPU: 1 ====
==== panic kernel thread: 0xffffff01be4aa000  PID: 0  on CPU: 1 ====
cmd: 
t_procp: 0xffffff01cffe7e10
  p_as: 0x0t_stk: 0xffffff0008da6f10  sp: 0xffffff0008da6790  t_stkbase: 0x0
t_pri: 60(FX)  pctcpu: 0.000000
t_lwp: 0x0  address translation failed for cpupart: 320 bytes @ 0xfed00000
bound psrset: -70932464  last CPU: 1  
idle: 1092044344150 ticks (126394 days 30 minutes 41.50 seconds)
start: Wed Jul 19 11:24:56 .*.*
age: 1092968065422 seconds (12650093 days 8 hours 23 minutes 42 seconds)
tstate:	TS_ONPROC - thread is being run on a processor
tflg:	T_PANIC - thread initiated a system panic
	T_DFLTSTK - stack is default size
tpflg:	TP_TWAIT - wait to be freed by lwp_wait
	TP_MSACCT - collect micro-state accounting information
tsched:	TS_LOAD - thread is in memory
	TS_DONT_SWAP - thread/LWP should not be swapped
	TS_SIGNALLED - thread was awakened by cv_signal()
pflag:	none set

pc:      unix:vpanic_common+0x13b:  addq   $0xf0,%rsp

unix:vpanic_common+0x13b()
unix:panic+0x94()
unix:die+0xdd()
unix:trap+0x175f()
unix:cmntrap_pushed+0x3d()
unix:mutex_enter+0xb()
klmmod:lm_svc+0x45()
nfs:nfssys+0x448()
unix:_sys_sysenter_post_swapgs+0x14b()
-- end of kernel thread's stack --


==== analyzing panic thread stack for trap frames ====

  no trap frames found
--

また、稼働中のシステムの様々な情報も取得することが可能です。
例として、メモリ情報やページ情報を確認するには、下記のように実行します。


[メモリ情報の確認]

--
SolarisCAT(live/11X)> meminfo
                              pages        bytes
physinstalled                976919   4001460224 (3.72G)
physmem                      974870   3993067520 (3.71G)
total_pages                  974869   3993063424 (3.71G)

freemem                      375851   1539485696 (1.43G)
avefree                      381934   1564401664 (1.45G)
avefree30                    374878   1535500288 (1.43G)
availrmem (nonswapable)      683612   2800074752 (2.60G)
availrmem_initial            974869   3993063424 (3.71G)
swapfs_minfree               121858    499130368 (476M)
sw_pending_size                            40960 (40K)

lotsfree                      15232     62390272 (59.5M)
desfree                        7616     31195136 (29.7M)
minfree                        3808     15597568 (14.8M)
throttlefree                   3808     15597568 (14.8M)

lookup failed for symbol segvn_pages_locked: symbol not found
pp_kernel(calculated)        290845   1191301120 (1.10G)
obp_pages                       512      2097152 (2M)
kcage_on:                0

shared memory (SM)                        540672 (528K)
intimate SM (ISM)                              0 (0)
dynamic ISM (DISM)                             0 (0)
locked DISM                       0            0 (0)
total locked SM                                0 (0) (0.00% of memory)
spt_used (ISM)                    0            0 (0)
segspt_minfree                    0            0 (0)

anoninfo: (physical == disk-backed)
  ani_max - total reservable physical swap                 488447 pages (1.86G)
  ani_free - unallocated physical and memory               220853 pages (862M)
  ani_phys_resv - reserved physical                        341070 pages (1.30G)
  ani_mem_resv - reserved memory                                0 pages (0)
  ani_locked_swap - swap locked in reserved mem swap            0 pages (0)

initial virtual swap available for reservation            1341458 pages (5.11G)
  ani_max + MAX((availrmem_initial - swapfs_minfree), 0)
current virtual swap available for reservation             709131 pages (2.70G)
  (ani_max - ani_phys_resv) + MAX((availrmem - swapfs_minfree), 0)

swap device                    pages           free
/dev/zvol/dsk/rpool/swap  488447 (1.86G)  488447 (1.86G)

tmpfs:
tmount          size  mount point
0xffffff01bc091140   456K  /etc/svc/volatile
0xffffff01be771918  6.10M  /tmp
0xffffff01be80a108    52K  /var/run
--

[ページ情報の確認]

--
# /opt/SUNWscat/bin/scat            
SolarisCAT(live/11X)> page summary
reading page table...
reading page_freelists...                                                     
reading page_cachelists...                                                    
reading page_hash...                                                          
                                                                              
total:               974869 (3.71G)
mapped:              545810 (2.08G)
unmapped:            429059 (1.63G)
modified:            238948 (933M)
read-only:                0 (0)
locked in memory:    273714 (1.04G)
soft locked:              0 (0)
shared-locked:       291166 (1.11G)
excl-locked:             63 (252K)
IO_INUSE:                 1 (4K)
FREE pages:          380541 (1.45G)
AGED pages:          230701 (901M)
NORELOC pages:            0 (0)

kernel(kvp):         171113 (668M)
anon:                242316 (946M)
exec:                  9163 (35.7M)
page cache:          168381 (657M)
page cache(mod):       1687 (6.58M)
free (cachelist):    149840 (585M)
NULL vnode !free:      3355 (13.1M) (ramdisk?)

free (freelist):     230701 (901M)

freelist:            227066 pages
       pages      pagesize
  =============== ========
   227059 (886M)  4K
        7 (14M)   2M

  total size:     944713728 (900M)
  constituent:         3577 pages

cachelist:           149429 (583M)

hashed:              740874 (2.82G)
       pages      pagesize
  =============== ========
   719370 (2.74G) 4K
    21504 (84M)   2M

     pages         modified         mapped      vnode
=============== =============== =============== =====
 234056 (914M)        0               1 (4K)    0
 171113 (668M)        0          141084 (551M)  unix(data):kvp+0x0  
 114705 (448M)        0          114705 (448M)  unix(data):zvp+0x0  
  24522 (95.7M)       0             510 (1.99M) 0xffffff01cd37f100  
   8688 (33.9M)       0             158 (632K)  0xffffff01cf1ca580  
   7914 (30.9M)       0            3791 (14.8M) 0xffffff01d0d33600  
   6160 (24M)         0            5214 (20.3M) 0xffffff01ccebe080  
...

     pages         modified         mapped      vnode ops
=============== =============== =============== =========
 285819 (1.09G)       0          255789 (999M)  0
 265316 (1.01G)  237261 (926M)   241334 (942M)  *genunix(bss):swap_vnodeops
 152844 (597M)        0           46491 (181M)  *zfs(bss):zfs_fvnodeops
  22657 (88.5M)       0            2168 (8.46M) 0xffffff01bb20b380
  12487 (48.7M)       0               0         *nfs(bss):nfs4_vnodeops
   1687 (6.58M)    1687 (6.58M)      27 (108K)  *tmpfs(bss):tmp_vnodeops
      3 (12K)         0               0         *specfs(bss):spec_vnodeops

--


http://blogs.sun.com/yappri/date/20090526 2009年 5月 26日 火曜日

ramdiskadm コマンドの紹介

今回は、カーネルのメモリ空間を RAM ディスクとして扱うことができる ramdiskadm コマンドを紹介します。
このコマンドで作成した RAM ディスクは、通常の高速なブロック型デバイス として扱えるので、ファイルシステムの作成や個別にマウントする事が可能です。

では、早速 RAM ディスクを作成してみましょう。
今回は、fastdisk という名前で 100 MB の RAM ディスクを作成します。

# ramdiskadm -a fastdisk 100m
/dev/ramdisk/fastdisk

これで 100MB の RAM ディスクが作成できました。
作成したディスクの状況は、引数なしの ramdiskadm コマンドで確認できます。

# ramdiskadm
ブロック型デバイス                                          サイズ  削除可能
/dev/ramdisk/fastdisk                                    104857600    はい

次に作成した RAMディスクに対してファイルシステムを作成します。

# newfs /dev/ramdisk/fastdisk
/dev/ramdisk/fastdisk: メディアタイプが見つかりません。システムによって決め
られたパラメータで処理を続行しています。
newfs: 新しいファイルシステム /dev/rramdisk/fastdisk を作成しますか: (y/n)? y

/dev/rramdisk/fastdisk: 全セクター数: 204600  (シリンダ数: 341、トラック数: 1、 セクター数: 600)
        99.9MB、22 シリンダグループ (16 c/g, 4.69MB/g, 2240 i/g)
スーパーブロックのバックアップの位置 (fsck -F ufs -o b=# のため) :
 32, 9632, 19232, 28832, 38432, 48032, 57632, 67232, 76832, 86432,
 115232, 124832, 134432, 144032, 153632, 163232, 172832, 182432, 192032, 201632

ファイルシステムの作成が完了したので早速マウントしてみましょう。

# mount /dev/ramdisk/fastdisk /mnt

# df -h /mnt
ファイルシステム     サイズ 使用済み 使用可能 容量      マウント先
/dev/ramdisk/fastdisk
                        94M   1.0M    83M     2%    /mnt

これで作成した RAM ディスクが通常のファイルシステム領域として利用可能に なりました。高速アクセスが求められる一時的な作業領域としてお使い下さい。

RAM ディスクを使用する注意点として、作成した RAM ディスクは、OS を再起動 すると設定情報が消えてしまいます。従いまして、RAM ディスク運用時は、OS 起動 時やアプリ起動時のスクリプトに RAM ディスクを作成する設定を入 れるなど考慮下さい。



(参考情報)
過去の 「やっぱり Sun がスキ!」blog 記事一覧はこちらを参照下さい。 http://wikis.sun.com/display/yappri/Home

http://blogs.sun.com/yappri/date/20090525 2009年 5月 25日 月曜日

iostat コマンドの読み方

はじめに

今回は iostat コマンドをご紹介したいと思います。iostat は I/O の統計情報を出力するコマンドです。物理ディスクやテープドライブ、ネットワーク越しにマウントしたファイルシステム、端末入出力等の入出力性能を監視する事が出来ます。I/O を監視するツールは他にも fsstat, nfsstat, zpool iostat, DTrace io Probider, kstat -p 'unix:0:biostats' 等がありますが、その中でも iostat は最も基本的で重要なコマンドです。是非ご活用下さい。

iostat のお勧めのオプション

-xnC 1

基本的なオプションとして -x, -n, -C オプションは常時付ける事をお勧めします。

 % iostat -xnC 1

x オプションは拡張表示を有効にするオプションです。iostat のデフォルトでは iostat が抜き出した幾つかのデバイスに付いて kps, tps, serv の 3 つの統計を表示するだけです。-x を付けると全てのデバイスが出力対象となり、出力される統計情報も増加します。I/O の解析を行う際は必須のオプションです。

n オプションはデバイス名を分かりやすく表示するオプションです。デフォルトではデバイス名は "ssd223" の様にドライバー名とインスタンス番号で表示されますが、-n オプションを付けると "c0t0d0" の様にディスクを特定しやすい名前で出力されます。これも必須のオプションと言って良いでしょう。常に付ける様にして下さい。

C オプションはコントローラ毎の統計情報も表示するオプションです。複数の HBA を使用しているシステムでは、コントローラをまたいで I/O 負荷を分散した方がスループットが上がります。個別のディスクの統計情報だけでなく、途中の経路における統計情報も取得する事で、より詳細な分析が可能になります。

1 はインターバルです。1 秒ごとに統計情報を表示します。iostat 実行の負荷は小さく、ログのサイズも今時のハードディスクのサイズを考えれば非常に小さいので、長期間の負荷を監視する場合でもより精度の高い情報を取得する為に 1 秒毎に出力する事をお勧めします。

その他のオプション

場合によっては -M や -z, -p, -m オプションを付けると便利です。

M オプションは "kr/s", "kw/s" を MB 表示に直します。内蔵ディスクでも数百 MB/s のスループットが出る時代ですし、FC の帯域はギガの単位ですので -M を付けた方が見易い場合も多くあります。ただし、細かい I/O が少量発生しているのを監視したい場合はデフォルトの KB 単位の方が良いかもしれません。

z オプションは出力結果の全ての性能値が 0 であった場合に表示を省略するオプションです。ディスクが沢山あって出力が画面をはみ出してしまう場合に便利です。毎回出力される行数が変わるのでログを取得する用途には向いていません。

p オプションはパーティション毎の統計情報も表示します。cXtXdXsX の sX 単位で出力されますので、どのスライスに I/O が発生しているかを見たい場合に使用して下さい。

m オプションは -n, -p と一緒に使用するとマウントポイントも表示します。どのデバイスに I/O が発生しているかが更に分かりやすくなります。

iostat の出力例

例1

 # iostat -xnC 1
 ...
                     extended device statistics
     r/s    w/s   kr/s   kw/s wait actv wsvc_t asvc_t  %w  %b device
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c0t6d0
     0.0   14.1    0.3  148.8  0.0  0.1    0.9    5.9   0   3 c1
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    3.9   0   1 c1t1d0
     0.0    3.3    0.0   36.6  0.0  0.0    0.6    4.1   0   1 c1t4d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t13d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t8d0
     0.0    3.3    0.0   36.6  0.0  0.0    0.6    4.2   0   1 c1t3d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.5   0   0 c1t5d0
     0.0    0.8    0.3    2.8  0.0  0.0    5.7   34.0   0   0 c1t0d0
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    4.2   0   1 c1t2d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 mikawa01.jp.iforce.net:vold(pid576)

例2

 # iostat -xnCmp 1
 ...
                     extended device statistics
     r/s    w/s   kr/s   kw/s wait actv wsvc_t asvc_t  %w  %b device
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c0t6d0
     0.0   14.1    0.3  148.8  0.0  0.1    0.9    5.9   0   3 c1
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    3.9   0   1 c1t1d0
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    3.9   0   1 c1t1d0s0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t1d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t1d0s3
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    1.0   0   0 c1t1d0s4
     0.0    3.3    0.0   36.6  0.0  0.0    0.6    4.1   0   1 c1t4d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t4d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.7   0   0 c1t4d0s3
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t4d0s4 
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t13d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t13d0s0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t13d0s1
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t13d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t8d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t8d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t8d0s3
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c1t8d0s4
     0.0    3.3    0.0   36.6  0.0  0.0    0.6    4.2   0   1 c1t3d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.6   0   0 c1t3d0s1
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t3d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    1.3   0   0 c1t3d0s5
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.5   0   0 c1t5d0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.7   0   0 c1t5d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.7   0   0 c1t5d0s3 
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t5d0s4
     0.0    0.8    0.3    2.8  0.0  0.0    5.7   34.0   0   0 c1t0d0
     0.0    0.8    0.3    2.8  0.0  0.0    5.7   34.0   0   0 c1t0d0s0 (/)
     0.0    0.0    0.0    0.0  0.0  0.0    0.0   19.2   0   0 c1t0d0s1
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t0d0s2
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    4.2   0   1 c1t2d0
     0.0    3.3    0.0   36.4  0.0  0.0    0.6    4.2   0   1 c1t2d0s0
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.8   0   0 c1t2d0s2
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    1.2   0   0 c1t2d0s6
     0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 mikawa01.jp.iforce.net:vold(pid576)

各カラムの意味

r/s(りーどぱーせかんど)

r/s は毎秒何回読み出しを行っているかを表しています。r/s と w/s を足し合わせた値が IOPS になります。なお、iostat の間隔を何秒に設定しても 1 秒辺りの数値で出力されます。

r/s の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::reads' 等で iostat の r/s と近い出力を得る事が可能です。iostat コマンドの中ではデバイスパスを比較してデバイスを選り分けている様です。

該当する kstat の値は主に以下の場所で更新されています。

w/s(らいとぱーせかんど)

w/s は毎秒何回書き込みを行っているかを表しています。細かい I/O が発生して書き込み回数が増えると、帯域が余っていてもディスクコントローラがボトルネックになる事があります。

w/s の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::writes' 等で iostat の w/s と近い出力を得る事が可能です。

該当する kstat の値は主に以下の場所で更新されています。

kr/s(きろりーどぱーせかんど)

kr/s は毎秒何 KB 読み出しを行っているかを表しています。r/s と w/s が IOPS を表していたのに対し、こちらは I/O のスループットを表しています。

kr/s の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::nread' 等で iostat の kr/s と近い出力を得る事が可能です。

該当する kstat の値は主に以下の場所で更新されています。

kw/s(きろらいとばーせかんど)

kw/s は毎秒何 KB 書き込みを行っているかを表しています。

kw/s の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::nwritten' 等で iostat の kw/s と近い出力を得る事が可能です。

該当する kstat の値は主に以下の場所で更新されています。

wait(うぇいと)

wait は I/O 要求が受け付けられたものの、実行まで待たされている I/O の数を表しています。実行待ちしている I/O 要求の数は kstat wait queue という名前で管理されています。

wait の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::wlentime' 等で iostat の wait と近い出力を得る事が可能です。

該当する kstat の値はカーネル内の kstat_waitq_enter(), kstat_waitq_exit(), kstat_waitq_to_runq() ,kstat_runq_back_to_waitq() で更新されています。

  • sun4u システムでは /usr/src/uts/sun4u/cpu/common_asm.s の stx %o5, [%o0 + QTYPE/**/LENTIME]; が更新ポイントです。KSTAT_Q_UPDATE() マクロの QTYPE 引数が KSTAT_IO_W だった時に KSTAT_IO_WLENTIME として評価されます。更に KSTAT_IO_WLENTIME は /usr/src/uts/sun4/ml/offsets.in 内の定義によって wlentime に変換されます(offsets.in は common_asm.s でインクルードされている assym.h の元ファイルです)。
  • sun4v では /usr/src/uts/sun4v/cpu/common_asm.s の stx %o5, [%o0 + QTYPE/**/LENTIME]; で更新されています。
  • x86 では /usr/src/uts/common/os/kstat_fr.c の kiop->wlentime += kiop->wcnt * wfix; と kiop->wlentime += delta * wcnt; で更新されています。

actv(あくてぃぶ)

actv は毎秒、デバイスによって処理されている I/O 要求の数を表しています。現在処理されている I/O の数は kstat run queue という名前で管理されています。

actv の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::rlentime' 等で iostat の actv と近い出力を得る事が可能です。

kstat の rlentime の値はカーネル内の kstat_runq_enter(), kstat_runq_exit(), kstat_waitq_to_runq(), kstat_runq_back_to_waitq() で更新されています。具体的には以下の場所です。

wsvc_t(うぇいとさーびすたいむ)

wsvc_t は I/O 要求が待機させられている時間の平均値をミリ秒単位で表しています。待機待ちの I/O 要求の個数(wait) を IOPS(r/s と w/s を足した値) で割った値です。

wsvc_t の値は ("wait" / ("r/s" + "w/s") * 1000) の計算式で求められます。

asvc_t(あくてぃぶさーびすたいむ)

asvc_t は I/O 要求の処理に掛かった時間の平均値をミリ秒単位で表しています。処理中の I/O 要求の個数(actv) を IOPS(r/s と w/s を足した値) で割った値です。

asvc_t の値は ("actv" / ("r/s" + "w/s") * 1000) の計算式で求められます。

%w(ぱーせんとうぇいと)

%w は待機させられている I/O 要求が存在している時間の割合です。/usr/src/uts/common/sys/kstat.h に図示されている様に、この値は I/O 要求の数と時間のリーマン和になっています。

%w の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::wtime' 等で iostat の %w と近い出力を得る事が可能です。

kstat の wrime の値はカーネル内の kstat_waitq_enter(), kstat_waitq_exit(), kstat_waitq_to_runq(), kstat_runq_back_to_waitq() で更新されています。具体的には以下の場所です。

%b(ぱーせんとびじー)

%b はディスクが busy 状態になっている時間の割合です。%w と同じ様にリーマン和になっています。

%b の値はカーネル内の kstat データから I/O デバイスの読み出し回数を取得しています。kstat コマンドでも kstat -p '/md|nfs|fd|st|dad|sd|ssd|lofi|ramdisk/:::rtime' 等で iostat の %r と近い出力を得る事が可能です。

kstat の rtime の値はカーネル内の kstat_runq_enter(), kstat_runq_exit(), kstat_waitq_to_runq(), kstat_runq_back_to_waitq() で更新されています。具体的には以下の場所です。

device(でばいす)

device はデバイス名です。

値の見方

iostat コマンドの初回の出力はデバイスがオンラインになってから現在までの累積値です。2 回目からの出力がリアルタイムの値ですので、注意して下さい。

まずは %w と %b がどれだけ出ているかを確認します。通常は %b が 100% に達してから %w が発生します。%w が出ている時は I/O リクエストを完全には捌けておらず、I/O ボトルネックになっている状態です。%w が出ておらず、%b も 100% までいっていない場合は I/O に余力がある状態です。この状態では I/O ボトルネックを心配する必要はありません。

基本的な情報として IOPS と I/O サイズ、I/O スループットの 3 つを把握して下さい。IOPS は毎秒幾つの I/O リクエストを捌けているかという情報です。IOPS は "r/s" + "w/s" で求める事が出来ます。IOPS が多い場合は I/O リクエストが多量に発生しており、負荷が高くなっている状態です。

I/O サイズは "kr/s" / "r/s" が平均読み出しサイズ、 "kw/s" / "w/s" が平均書き込みサイズです。平均 I/O サイズが小さい場合は細かい書き込みが発生しており、一般的に性能が出にくい状態です。ある特定のプロセスがどんなサイズの I/O リクエストを出しているかは DTrace や truss で確認する事が出来ます。以下の様に truss を実行すると、入出力先のデバイス、I/O のサイズ、読み書きされているデータの中身、I/O に掛かった時間等、詳細な情報を入手する事が出来ます。

 % truss -E -vall -wall -rall -p 

I/O スループットは "kr/s" と "kw/s" のカラムを見ます。"kr/s" が毎秒何 KB 読み出しているか、"kw/s" が何 KB 書き込んでいるかを示しています。スループットの値は I/O パターンやディスクのレイアウトにも依りますが、期待したスループットが達成されているか確認して下さい。

I/O の重要な調査ポイントとして、発行されている I/O の特性も見極める必要があります。read only なのか write intensive なのか read と write の混在なのか、sequential access か random access か、等の I/O 特性によって I/O の性能は変化します。これらの情報は RAID 構成を決定する際のヒントにもなります。"r/s" が増加していて "w/s" が 0 の場合は read only access で、逆の場合は write only access です。I/O 特性が read only でデータサイズがそれ程大きくない場合は tmpfs にデータを置くと性能が大きく改善します。sequential か random かを iostat で正確に切り分ける方法はありませんが、read / write が両方発生している場合や、I/O サイズが不規則に変化している場合は random access の可能性が高いです。

関連するソースファイル

iostat の出力は iostat.c の show_disk() 関数にまとめられています。kstat からのデータの取得は acquire_iodevs.c の中で行っています。

参考文献

終わりに

以上、iostat の実装と読み方に付いて解説しました。IOPS、I/O サイズ、スループット、wait queue, run queue 等の情報を活用する事でサーバを健全な状態で運用する事が可能になります。vmstatmpstat 等のツールとともに頻繁に使用するツールですので、是非使い方を憶えて有効活用して下さい。