b.l0g.jp     About     Archive     Feed

sarコマンドでシステムのボトルネックを探る(1)

前回のエントリでは、システムのレスポンスが悪化している場合、まずとっかかりとしてtopコマンドを実行し、ロードアベレージを確認する方法を書いた。さらに踏み込んで、何が負荷の原因なのかを探るために、sarコマンドを使う方法について書く。

sarコマンドをオプションをつけずに実行すると、以下のような出力が得られる。ファイルを指定しないと、コマンドを実行した当日の0:00から直前までの10分おきの情報が表示される。過去の情報は/var/log/saディレクトリ以下に保存されており、「sar -f sa07」などと指定すると、そのファイルに保存された情報が閲覧できる。saの後の数字は日付を表している。

sarを実行してもコマンドが見つからない場合、sysstatパッケージがインストールされていないので、インストールすべし。

  
[doublemarket@hoge ~]$ sar
  
Linux 2.6.18-194.8.1.el5 (hoge) 2011年02月15日

00時00分01秒 CPU %user %nice %system %iowait %steal %idle
  
00時10分01秒 all 0.05 0.00 0.08 0.02 0.00 99.85
  
00時20分01秒 all 0.03 0.00 0.08 0.02 0.00 99.88
  
00時30分01秒 all 0.07 0.00 0.11 0.02 0.00 99.79
  
:
  
:
  
20時00分01秒 all 0.03 0.00 0.06 0.00 0.00 99.90
  
20時10分01秒 all 0.06 0.00 0.11 0.03 0.00 99.80
  
20時20分01秒 all 0.16 0.00 0.14 0.03 0.00 99.67
  
20時30分01秒 all 1.11 0.00 0.27 0.12 0.00 98.50
  
20時40分01秒 all 0.08 0.00 0.12 0.05 0.00 99.76
  
平均値: all 0.08 0.00 0.10 0.09 0.00 99.73
  

ここで得られる結果は、sar -uと同じものである。それぞれの列の意味は以下の通り。

user
ユーザプログラムの実行に使用されたCPUリソースの割合
nice
niceによる優先度を処理するために使用されたCPUリソースの割合
system
カーネルが使用したCPUリソースの割合
iowait
I/O待ちの割合
idle
I/O待ち以外でCPUが待ち状態だった割合(何もしていない時間)

なお、マルチCPUの環境の場合ここに表示されているのは、全CPUの合算使用率になっている。それぞれのCPUの使用率を確認したい場合、「sar -P ALL」を実行する。意外と処理が特定のCPUに偏っていたりするので、こちらも確認してみた方がよい。

→ sarコマンドの実行結果からシステムの負荷状況に関して、以下の傾向がつかめる。

userの値だけが高い(他の値は低いまま)
CPUリソースを必要とするアプリケーションが動作している。
topやps auwxなどのコマンドでプロセスごとのCPU使用率を調べ、無限ループなどの不具合によるCPU使用率の上昇でないかなど、異常を確認。単に処理が重くなっているだけなら、スケールアップ(CPUを高速化)、スケールアウト(マシンを増設)を検討する。
iowaitの値が高い
そのマシンに求められる処理に対して、ハードディスクの速度が追いついていない。アプリケーションやミドルウェア(特にデータベースなど)のキャッシュの仕組みを見直したり、読み書きに使う物理的なディスクを分散させるなどして、なるべくディスクの読み書きが発生しない方法を考える。それでも高いままなら、より高速なディスクを使うしかない。なおたいていの場合は
・アプリケーション自体がディスクにアクセスする速度が遅い
・メモリが不足していてスワップ領域(つまりディスク)へのアクセスが頻発していて遅い
の2つに問題を分けることができる。このうちのどちらかという判断は、sar -rの結果などを見る必要がある。
systemの値が高い
仕組み的にいえば、コンテキストスイッチがたくさん発生していると値が上がるはずなので、必要以上にたくさんのプログラムを並列に処理しすぎていると、この値が異常に上がるということになるが、よく分からない。

sarコマンドには、メモリやディスク、ネットワークなどに関する情報が得られるよう、他にも色々なオプションがある。

topコマンドでロードアベレージを見る

Linuxにおいて、システムの全体的な負荷状況を知りたい時、リアルタイムの状況を知るにはtopコマンド、ある程度の期間に渡る傾向をつかむにはsar(sysstat)の結果を確認するのが一般的だろう。

そのサーバ上で動作するアプリケーションの動作が遅いなどといったパフォーマンス劣化がある時、まず最初に見るべきがロードアベレージの値。これは「CPUの処理を待っているタスクの数」であり、ほとんど何も処理を行っていない時には0になる。

topコマンドの表示内容

  
top - 16:04:44 up 15 days, 21:40, 2 users, load average: 0.00, 0.00, 0.00
  
Tasks: 108 total, 2 running, 105 sleeping, 0 stopped, 1 zombie
  
Cpu(s): 0.0% us, 0.0% sy, 0.0% ni, 100.0% id, 0.0% wa, 0.0% hi, 0.0% si
  
Mem: 8113608k total, 8082584k used, 31024k free, 69652k buffers
  
Swap: 8385920k total, 352k used, 8385568k free, 6008888k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
  
1 root 16 0 1848 552 472 S 0.0 0.0 0:01.32 init
  
2 root RT 0 0 0 0 S 0.0 0.0 0:17.52 migration/0
  
3 root 34 19 0 0 0 S 0.0 0.0 0:00.40 ksoftirqd/0
  
4 root RT 0 0 0 0 S 0.0 0.0 0:15.31 migration/1
  
5 root 34 19 0 0 0 S 0.0 0.0 0:00.32 ksoftirqd/1
  
6 root RT 0 0 0 0 S 0.0 0.0 0:11.21 migration/2
  
7 root 34 19 0 0 0 S 0.0 0.0 0:00.17 ksoftirqd/2
  
8 root RT 0 0 0 0 S 0.0 0.0 0:15.26 migration/3
  
9 root 34 19 0 0 0 S 0.0 0.0 0:00.25 ksoftirqd/3
  
10 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 events/0
  
11 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 events/1
  
12 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 events/2
  
13 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 events/3
  
14 root 7 -10 0 0 0 S 0.0 0.0 0:00.00 khelper
  
15 root 15 -10 0 0 0 S 0.0 0.0 0:00.00 kacpid
  
95 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 kblockd/0
  
96 root 5 -10 0 0 0 S 0.0 0.0 0:00.00 kblockd/1
  

1行目の右端に表示されているのがロードアベレージの値。前述の通りCPUの処理を待っているタスクの数がロードアベレージなので、値が大きければ大きいほどCPUの処理を待っているタスクが多いということになり、それだけサーバのレスポンスが落ちることになる。ただし、単に計算を待っているだけではなく、IOの処理を待っている場合もこの値が大きくなるので、ロードアベレージが大きいことが即CPUが遅いことになるわけではない。CPUそのもの、メモリ、ディスク、それ以外、の何が原因で遅いか調査する必要がある。

なお、topでのロードアベレージの表示は、左から、1分、5分、15分間の平均値になっている。つまり、左の方が値が大きければ、直近の数分間で急に負荷が上がっていることを表す。

言わずもがなだが下半分には、CPUの使用率順に並んだプロセス一覧が表示されるので、ここからCPU負荷が高かったりメモリの使用量が多いアプリケーションが何なのかは大体つかめる。topからなんとなくのあたりをつけたあと、何がボトルネックになっているかを探すには、sarコマンドで過去のパフォーマンスデータを確認していく。

logrotateのローテート世代数を減らす時の注意

本当は「山に行きました!」というブログを投稿したいところなのだが、さっぱり行ける雰囲気がないので、腹いせに技術系の投稿を続けてる。

logrotateを使ってログのローテートを行っている状況で、ログファイルの総容量が大きくなり、世代数を減らさざるを得ないときのこと。「rotate 世代数」の指定を減らしても、古い世代数は削除されない。

具体的には、以下の例。当初logrotate.confで以下の設定をしていたとする。

  
\# see "man logrotate" for details
  
\# rotate log files daily
  
daily

\# keep 10 days worth of backlogs
  
rotate 10

\# create new (empty) log files after rotating old ones
  
create

\# uncomment this if you want your log files compressed
  
#compress

\# RPM packages drop log rotation information into this directory
  
include /etc/logrotate.d
  

この場合、1日1回ローテートされたファイルが10回分保存される。例えば以下のように。

  
ls -v /var/log/httpd/access_log*
  
access\_log access\_log.4 access_log.8
  
access\_log.1 access\_log.5 access_log.9
  
access\_log.2 access\_log.6 access_log.10
  
access\_log.3 access\_log.7
  

ここで、アクセスログ1ファイルずつの容量が増えてきて、ディスク空き容量が減ってきた場合、保存する世代数を減らして対処する場合、「rotate 世代数」の世代数を減らしても、古い世代が一斉に削除されるわけではない。

rotate 5とした場合、次のローテート後には以下のようになる。

  
access\_log access\_log.4 access_log.9
  
access\_log.1 access\_log.5 access_log.10
  
access\_log.2 access\_log.7
  
access\_log.3 access\_log.8
  

つまり、6世代目が消えるだけで、7世代目以降は自動的には削除されないため、手動で削除する必要がある。

これだけ。これが分からなくて危なくディスク使用率が100%になるところだった。