4.2. ディスク

以下のセクションでは、ディスクおよび I/O アクティビティーを監視するスクリプトを説明します。

4.2.1. ディスク読み取り/書き込みトラフィックの要約

このセクションでは、どのプロセスが最も重いディスクの読み取り/書き込みをシステムに実行しているかを特定する方法について説明します。

例4.9 disktop.stp

#!/usr/bin/stap
#
# Copyright (C) 2007 Oracle Corp.
#
# Get the status of reading/writing disk every 5 seconds,
# output top ten entries 
#
# This is free software,GNU General Public License (GPL);
# either version 2, or (at your option) any later version.
#
# Usage:
#  ./disktop.stp
#

global io_stat,device
global read_bytes,write_bytes

probe vfs.read.return {
  if ($return>0) {
    if (devname!="N/A") {/*skip read from cache*/
      io_stat[pid(),execname(),uid(),ppid(),"R"] += $return
      device[pid(),execname(),uid(),ppid(),"R"] = devname
      read_bytes += $return
    }
  }
}

probe vfs.write.return {
  if ($return>0) {
    if (devname!="N/A") { /*skip update cache*/
      io_stat[pid(),execname(),uid(),ppid(),"W"] += $return
      device[pid(),execname(),uid(),ppid(),"W"] = devname
      write_bytes += $return
    }
  }
}

probe timer.ms(5000) {
  /* skip non-read/write disk */
  if (read_bytes+write_bytes) {

    printf("\n%-25s, %-8s%4dKb/sec, %-7s%6dKb, %-7s%6dKb\n\n",
           ctime(gettimeofday_s()),
           "Average:", ((read_bytes+write_bytes)/1024)/5,
           "Read:",read_bytes/1024,
           "Write:",write_bytes/1024)

    /* print header */
    printf("%8s %8s %8s %25s %8s %4s %12s\n",
           "UID","PID","PPID","CMD","DEVICE","T","BYTES")
  }
  /* print top ten I/O */
  foreach ([process,cmd,userid,parent,action] in io_stat- limit 10)
    printf("%8d %8d %8d %25s %8s %4s %12d\n",
           userid,process,parent,cmd,
           device[process,cmd,userid,parent,action],
           action,io_stat[process,cmd,userid,parent,action])

  /* clear data */
  delete io_stat
  delete device
  read_bytes = 0
  write_bytes = 0  
}

probe end{
  delete io_stat
  delete device
  delete read_bytes
  delete write_bytes
}
例4.9「disktop.stp」 は、ディスクに重い読み取りまたは書き込みを行なっているプロセス上位 10 位を出力します。例4.10「例4.9「disktop.stp」 のサンプル出力」 はこのスクリプトのサンプル出力となり、記載されているプロセスについて以下のデータが含まれます。
  • UID — ユーザー ID。ユーザー ID が 0 の場合は、root ユーザーを指します。
  • PID — プロセスの ID。
  • PPID — プロセスの 親プロセスの ID。
  • CMD — プロセスの名前。
  • DEVICE — プロセスが読み取りまたは書き込みを行なっているストレージデバイス。
  • T — プロセスが実行したアクションのタイプ。W は書き込みを、R は読み取りを指します。
  • BYTES — ディスクから読み取った、またはディスクに書き込んだデータ量。
例4.9「disktop.stp」 の日時に関する出力は、ctime() と gettimeofday_s() の関数で返されます。ctime() は、Unix 時間 (1970 年 1 月 1 日) 以降の秒単位経過をカレンダー時刻で引き出します。gettimeofday_s() は、Unix 時間以降の実際の秒数をカウントします。これは、出力についてかなり正確でヒューマンリーダブルなタイムスタンプを提供します。
このスクリプトでは、$return は各プロセスが仮想ファイルシステムから読み取ったまたは書き込んだ実際のバイト数を保存するローカル変数です。$return は return プローブ(vfs.read.return や vfs.read.return など) での使用のみが可能です。

例4.10 例4.9「disktop.stp」 のサンプル出力

[...]
Mon Sep 29 03:38:28 2008 , Average:  19Kb/sec, Read: 7Kb, Write: 89Kb
UID      PID     PPID                       CMD   DEVICE    T    BYTES
0    26319    26294                   firefox     sda5    W        90229
0     2758     2757           pam_timestamp_c     sda5    R         8064
0     2885        1                     cupsd     sda5    W         1678
Mon Sep 29 03:38:38 2008 , Average:   1Kb/sec, Read: 7Kb, Write: 1Kb
UID      PID     PPID                       CMD   DEVICE    T    BYTES
0     2758     2757           pam_timestamp_c     sda5    R         8064
0     2885        1                     cupsd     sda5    W         1678

4.2.2. ファイル読み取り/書き込みの I/O 時間の追跡

このセクションでは、各プロセスのファイルの読み取りおよび書き込み時間を監視する方法を説明します。これは、あるシステム上でどのファイルの読み込みが遅いかということを判断する際に便利です。

例4.11 iotime.stp

global start
global entry_io
global fd_io
global time_io

function timestamp:long() {
  return gettimeofday_us() - start
}

function proc:string() {
  return sprintf("%d (%s)", pid(), execname())
}

probe begin {
 start = gettimeofday_us()
}

global filenames
global filehandles
global fileread
global filewrite

probe syscall.open {
  filenames[pid()] = user_string($filename)
} 

probe syscall.open.return {
  if ($return != -1) {
    filehandles[pid(), $return] = filenames[pid()]
    fileread[pid(), $return] = 0
    filewrite[pid(), $return] = 0
  } else {
    printf("%d %s access %s fail\n", timestamp(), proc(), filenames[pid()])
  }
  delete filenames[pid()]
}

probe syscall.read {
  if ($count > 0) {
    fileread[pid(), $fd] += $count
  }
  t = gettimeofday_us(); p = pid()
  entry_io[p] = t
  fd_io[p] = $fd
}

probe syscall.read.return {
  t = gettimeofday_us(); p = pid()
  fd = fd_io[p]
  time_io[p,fd] <<< t - entry_io[p]
}

probe syscall.write {
  if ($count > 0) {
    filewrite[pid(), $fd] += $count
  }
  t = gettimeofday_us(); p = pid()
  entry_io[p] = t
  fd_io[p] = $fd
}

probe syscall.write.return {
  t = gettimeofday_us(); p = pid()
  fd = fd_io[p]
  time_io[p,fd] <<< t - entry_io[p]
}

probe syscall.close {
  if (filehandles[pid(), $fd] != "") {
    printf("%d %s access %s read: %d write: %d\n",  timestamp(), proc(),
           filehandles[pid(), $fd], fileread[pid(), $fd], filewrite[pid(), $fd])
    if (@count(time_io[pid(), $fd]))
      printf("%d %s iotime %s time: %d\n",  timestamp(), proc(),
             filehandles[pid(), $fd], @sum(time_io[pid(), $fd]))
   }
  delete fileread[pid(), $fd]
  delete filewrite[pid(), $fd]
  delete filehandles[pid(), $fd]
  delete fd_io[pid()]
  delete entry_io[pid()]
  delete time_io[pid(),$fd]
}
例4.11「iotime.stp」 では、システムコールが開かれる、閉じる、ファイルから読み取る、およびファイルに書き込む際に、毎回これを追跡します。例4.11「iotime.stp」 はシステムコールがアクセスする各ファイルについて、読み取りもしくは書き込みが終了するまでの時間をマイクロ秒単位でカウントし、読み取りもしくは書き込みされたデータ量をバイト単位で追跡します。
例4.11「iotime.stp」 は、ローカル変数 $count を使ってシステムコールが読み取りまたは書き込みを 試みた データ量 (バイト単位) も追跡します。( 「ディスク読み取り/書き込みトラフィックの要約」 の 例4.9「disktop.stp」 で使用されている) $return は、実際に 読み取り/書き込みされたデータ量を保存することに注意してください。$count を使用できるのは、(syscall.read や syscall.write など) データの読み取りや書き込みを追跡するプローブのみです。

例4.12 例4.11「iotime.stp」 のサンプル出力

[...]
825946 3364 (NetworkManager) access /sys/class/net/eth0/carrier read: 8190 write: 0
825955 3364 (NetworkManager) iotime /sys/class/net/eth0/carrier time: 9
[...]
117061 2460 (pcscd) access /dev/bus/usb/003/001 read: 43 write: 0
117065 2460 (pcscd) iotime /dev/bus/usb/003/001 time: 7
[...]
3973737 2886 (sendmail) access /proc/loadavg read: 4096 write: 0
3973744 2886 (sendmail) iotime /proc/loadavg time: 11
[...]
例4.12「例4.11「iotime.stp」 のサンプル出力」 では、以下のデータがプリントアウトされます。
  • タイムスタンプ (マイクロ秒単位)
  • プロセス ID およびプロセス名
  • access または iotime のフラグ
  • アクセスされたファイル
プロセスがデータの読み取りまたは書き込みを実行すると、access と iotime の行のペアが一緒に表示されます。access 行のタイムスタンプは、そのプロセスがファイルにアクセスを開始した時間を指します。その行の最後には、読み取り/書き込みされたデータ量がバイト単位で表示されます。iotime の行では、読み取り/書き込みにプロセスが費やした時間がマイクロ秒単位で表示されます。
access 行の後に iotime 行が続いていない場合は、プロセスがデータの読み取りまたは書き込みを行わなかったことを意味します。

4.2.3. 累積 I/O の追跡

このセクションでは、システムへの累積 I/O の量を追跡する方法を説明します。

例4.13 traceio.stp

#! /usr/bin/env stap
# traceio.stp
# Copyright (C) 2007 Red Hat, Inc., Eugene Teo <eteo@redhat.com>
# Copyright (C) 2009 Kai Meyer <kai@unixlords.com>
#   Fixed a bug that allows this to run longer
#   And added the humanreadable function
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License version 2 as
# published by the Free Software Foundation.
#

global reads, writes, total_io

probe vfs.read.return {
  reads[pid(),execname()] += $return
  total_io[pid(),execname()] += $return
}

probe vfs.write.return {
  writes[pid(),execname()] += $return
  total_io[pid(),execname()] += $return
}

function humanreadable(bytes) {
  if (bytes > 1024*1024*1024) {
    return sprintf("%d GiB", bytes/1024/1024/1024)
  } else if (bytes > 1024*1024) {
    return sprintf("%d MiB", bytes/1024/1024)
  } else if (bytes > 1024) {
    return sprintf("%d KiB", bytes/1024)
  } else {
    return sprintf("%d   B", bytes)
  }
}

probe timer.s(1) {
  foreach([p,e] in total_io- limit 10)
    printf("%8d %15s r: %12s w: %12s\n",
           p, e, humanreadable(reads[p,e]),
           humanreadable(writes[p,e]))
  printf("\n")
  # Note we don't zero out reads, writes and total_io,
  # so the values are cumulative since the script started.
}
例4.13「traceio.stp」 は、I/O トラフィックに応じた上位 10 位の実行可能ファイルをプリントします。さらに、これらの上位 10 位の実行可能ファイルによる I/O 読み取りおよび書き込みの累積分量も追跡します。この情報は降順で 1 秒ごとに追跡、プリントアウトされます。
例4.13「traceio.stp」 では、「ディスク読み取り/書き込みトラフィックの要約」 の 例4.9「disktop.stp」 でも使用されているローカル変数 $return が使用されていることに注意してください。

例4.14 例4.13「traceio.stp」 のサンプル出力

[...]
           Xorg r:   583401 KiB w:        0 KiB
       floaters r:       96 KiB w:     7130 KiB
multiload-apple r:      538 KiB w:      537 KiB
           sshd r:       71 KiB w:       72 KiB
pam_timestamp_c r:      138 KiB w:        0 KiB
        staprun r:       51 KiB w:       51 KiB
          snmpd r:       46 KiB w:        0 KiB
          pcscd r:       28 KiB w:        0 KiB
     irqbalance r:       27 KiB w:        4 KiB
          cupsd r:        4 KiB w:       18 KiB
           Xorg r:   588140 KiB w:        0 KiB
       floaters r:       97 KiB w:     7143 KiB
multiload-apple r:      543 KiB w:      542 KiB
           sshd r:       72 KiB w:       72 KiB
pam_timestamp_c r:      138 KiB w:        0 KiB
        staprun r:       51 KiB w:       51 KiB
          snmpd r:       46 KiB w:        0 KiB
          pcscd r:       28 KiB w:        0 KiB
     irqbalance r:       27 KiB w:        4 KiB
          cupsd r:        4 KiB w:       18 KiB

4.2.4. I/O 監視 (デバイスごと)

このセクションでは、特定のデバイス上の I/O アクティビティーを監視する方法について説明します。

例4.15 traceio2.stp

#! /usr/bin/env stap

global device_of_interest

probe begin {
  /* The following is not the most efficient way to do this.
      One could directly put the result of usrdev2kerndev()
      into device_of_interest.  However, want to test out
      the other device functions */
  dev = usrdev2kerndev($1)
  device_of_interest = MKDEV(MAJOR(dev), MINOR(dev))
}

probe vfs.write, vfs.read
{
  if (dev == device_of_interest)
    printf ("%s(%d) %s 0x%x\n",
            execname(), pid(), probefunc(), dev)
}
例4.15「traceio2.stp」 は、全体デバイス番号という引数 1 つを取ります。この番号を取得するには、stat -c "0x%D" directory を使用します。ここでの directory は、監視するデバイス上にあるものにします。
usrdev2kerndev() 関数は、全体デバイス番号をカーネルが理解する書式に変換します。usrdev2kerndev() による出力は、MKDEV()、MINOR()、および MAJOR() の関数と併せて、特定デバイスのメジャーおよびマイナー番号の決定に使用されます。
例4.15「traceio2.stp」 の出力には、読み取り/書き込みを実行しているプロセスの名前と ID、実行している関数 (vfs_read または vfs_write)、およびカーネルデバイス番号が含まれます。
以下の例は、stap traceio2.stp 0x805 の出力の抜粋です。ここでの 0x805 は、/home の全体デバイス番号です。/home は /dev/sda5 に存在しており、これが監視対象のデバイスになります。

例4.16 例4.15「traceio2.stp」 のサンプル出力

[...]
synergyc(3722) vfs_read 0x800005
synergyc(3722) vfs_read 0x800005
cupsd(2889) vfs_write 0x800005
cupsd(2889) vfs_write 0x800005
cupsd(2889) vfs_write 0x800005
[...]

4.2.5. ファイルの読み取りおよび書き込みの監視

このセクションでは、ファイルの読み取りおよび書き込みをリアルタイムで監視する方法について説明します。

例4.17 inodewatch.stp

#! /usr/bin/env stap

probe vfs.write, vfs.read
{
  # dev and ino are defined by vfs.write and vfs.read
  if (dev == MKDEV($1,$2) # major/minor device
      && ino == $3)
    printf ("%s(%d) %s 0x%x/%u\n",
      execname(), pid(), probefunc(), dev, ino)
}
例4.17「inodewatch.stp」 は、ファイルについての以下の情報をコマンドラインの引数として取ります。
  • ファイルのメジャーデバイス番号。
  • ファイルのマイナーデバイス番号。
  • ファイルの inode 番号。
これらの情報を取得するには、stat -c '%D %i' filename を使用します。ここでの filename は、絶対パスになります。
たとえば、/etc/crontab ファイルを監視するには、まず stat -c '%D %i' /etc/crontab を実行します。これで以下の出力が得られます。 
805 1078319
805 は、ベース 16 (16 進数) のデバイス番号です。最後の 2 桁がマイナーデバイス番号で、その上の数字がメジャー番号です。1078319 は inode 番号になります。/etc/crontab の監視を開始するには、stap inodewatch.stp 0x8 0x05 1078319 を実行します (0x 接頭辞は、ベース 16 の値を示します)。
このコマンドの出力には、読み取り/書き込みを実行しているプロセスの名前と ID、実行している関数 (vfs_read または vfs_write)、デバイス番号 (16 進法形式)、および inode 番号が含まれます。例4.18「例4.17「inodewatch.stp」 のサンプル出力」 は、stap inodewatch.stp 0x8 0x05 1078319 の出力になります (スクリプトの実行中に cat /etc/crontab を実行した場合)。

例4.18 例4.17「inodewatch.stp」 のサンプル出力

cat(16437) vfs_read 0x800005/1078319
cat(16437) vfs_read 0x800005/1078319

4.2.6. ファイル属性の変更の監視

このセクションでは、プロセスがターゲットファイルの属性を変更したかどうかをリアルタイムで監視する方法について説明します。

例4.19 inodewatch2-simple.stp

global ATTR_MODE = 1

probe kernel.function("inode_setattr") {
  dev_nr = $inode->i_sb->s_dev
  inode_nr = $inode->i_ino

  if (dev_nr == ($1 << 20 | $2) # major/minor device
      && inode_nr == $3
      && $attr->ia_valid & ATTR_MODE)
    printf ("%s(%d) %s 0x%x/%u %o %d\n",
      execname(), pid(), probefunc(), dev_nr, inode_nr, $attr->ia_mode, uid())
}
「ファイルの読み取りおよび書き込みの監視」 の 例4.17「inodewatch.stp」 のように、例4.19「inodewatch2-simple.stp」 はターゲットファイルのデバイス番号 (整数形式) と inode 番号を引数として取ります。この情報の取得方法については、「ファイルの読み取りおよび書き込みの監視」 を参照してください。
例4.19「inodewatch2-simple.stp」 の出力は 例4.17「inodewatch.stp」 の場合と似ていますが、例4.19「inodewatch2-simple.stp」 には監視対象ファイルの属性変更と、変更を行ったユーザーの ID (uid()) が含まれている点が異なります。例4.20「例4.19「inodewatch2-simple.stp」 のサンプル出力」 は、例4.19「inodewatch2-simple.stp」 の出力になります。/home/joe/bigfile の監視中に、ユーザー joe が chmod 777 /home/joe/bigfile と chmod 666 /home/joe/bigfile を実行しています。

例4.20 例4.19「inodewatch2-simple.stp」 のサンプル出力

chmod(17448) inode_setattr 0x800005/6011835 100777 500
chmod(17449) inode_setattr 0x800005/6011835 100666 500