ablog

不器用で落着きのない技術者のメモ

性能問題の切り分け方法について考えてみる

つれづれなるままに、日ぐらしパソコンに向かひて、心にうつりゆくデータベースの性能問題の切り分け方法をそこはかとなく書き付くれば、あやしうこそ物狂ほしけれ。なエントリ(書きかけ)。一度、脳内をフラッシュしてからまとめるべし。

性能問題による影響

性能問題による影響を以下の2つに分類する。

システム全体が遅い

一部の処理が遅い

性能問題の原因

性能問題の原因を以下の2つに分類する。

交通量が多い

経路の途中で詰まっている
  • 車線減少や通行止めなどで渋滞している
  • 例)年度末の工事による車線減少、飲酒の検問、交通事故による通行止めなどで経路のどこかで詰まっている

切り分け手順の分類

システム全体が遅いケースと一部の処理が遅いケースで切り分け手順は変わる。
切り分けはOSレイヤーとデータベースレイヤーの2つの観点から行う。

  • システム全体が遅いケース
    • 交通量が多いか
    • 経路の途中で詰まっていないか
  • 一部の処理が遅いケース
    • 交通量が多いか
    • 経路の途中で詰まっていないか

切り分けフロー

ワイルドな切り分けフローを書いてみる。

  • システム全体が遅いケース
    • 交通量が多いか(OSレイヤー)


sar でだいたいのことはできると思うが、とりあえずベタに書いてみる。

$ uptime
 13:30:10 up 2 days, 23:46,  1 user,  load average: 3.78, 3.01, 1.76

uptime で load average を見る*1。load average は CPU待ち*2 + I/O待ち*3のプロセス数*4の平均値。左から1分間、5分間、15分間の平均値。この数をCPUコア数で割って2以上だと待ちが発生している*5。例えると、load average はマック*6のレジに並んでいるお客さんの行列の人数。例えば、合計でお客さん3人並んでいても、レジが3台あれば待ちは発生していないので無問題。ちなみにこの環境は2コアなので、load average の直近1分間の平均が 3.78 は結構重い状態。2コアとも常に処理を実行中で1プロセスが待ちの状態が1分続いている。

$ sar  -s 13:00:00
01:00:01 PM       CPU     %user     %nice   %system   %iowait    %steal     %idle
01:10:01 PM       all      0.11      0.00      0.06     15.45      0.10     84.28
01:20:01 PM       all      0.04      0.00      0.05     15.60      0.11     84.21
01:30:01 PM       all     74.00      0.00      0.06      2.56      0.07     23.31
Average:          all     24.72      0.00      0.06     11.20      0.09     63.93

次に sar でCPU使用率を見る。-sオプションで表示開始時刻を指定している*7。まず %user と %system を見る。DBのプロセスなどユーザープログラムが忙しいときは %user の値が大きくなる。%system はシステムコールカーネルスレッドなどOSカーネルがCPUを使用した割合*8。通常 %system がそんなに大きい値になることは少ない。%user でも %system でもCPU使用率が高くなる要因として、単純に処理量が多い以外にスピンロックで大量のプロセスやスレッドがCPUを使いながら待機したり、スピン*9してハングしているなどのケースがある。100 ÷ CPUコア数*10の倍数の場合は、一部のコアの使用率が100%になっているかもという感覚を持っておくとよい。例えば、4コアで25%だと1コアが100%になっていることがある。%iowait が高い場合は、CPUは空いていてプロセスがI/O待ちでスリープしている割合が高くI/Oがボトルネックになっていることが多い*11

$ sar -P ALL -s 13:00:00
01:00:01 PM       CPU     %user     %nice   %system   %iowait    %steal     %idle
01:10:01 PM       all      0.11      0.00      0.06     15.45      0.10     84.28
01:10:01 PM         0      0.16      0.00      0.07     29.06      0.11     70.60
01:10:01 PM         1      0.06      0.00      0.05      1.84      0.10     97.95
01:20:01 PM       all      0.04      0.00      0.05     15.60      0.11     84.21
01:20:01 PM         0      0.06      0.00      0.07     29.72      0.11     70.04
01:20:01 PM         1      0.02      0.00      0.03      1.48      0.10     98.37
01:30:01 PM       all     74.00      0.00      0.06      2.56      0.07     23.31
01:30:01 PM         0     75.46      0.00      0.08      4.98      0.08     19.40
01:30:01 PM         1     72.55      0.00      0.04      0.13      0.07     27.21
Average:          all     24.72      0.00      0.06     11.20      0.09     63.93
Average:            0     25.23      0.00      0.07     21.25      0.10     53.34
Average:            1     24.21      0.00      0.04      1.15      0.09     74.51

sar -P ALL でCPUコア別の使用率を確認する。この環境は0番と1番の2コアであることがわかる。全コアの平均ではCPU使用率が低く見えても、内訳を見ると実は一部のコアだけ100%で他のコアは暇ということもある。

$ top
top - 13:46:10 up 3 days, 2 min,  4 users,  load average: 4.83, 3.90, 2.93
Tasks: 116 total,   5 running, 111 sleeping,   0 stopped,   0 zombie
Cpu(s): 97.1%us,  2.9%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   2097152k total,  2085004k used,    12148k free,   143416k buffers
Swap:  6258680k total,    61344k used,  6197336k free,  1513876k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
15042 oracle    25   0 77860 1416 1116 R 99.7  0.1  23:39.52 perl -e while(1){}
15046 oracle    25   0 77860 1420 1116 R 97.8  0.1  17:50.85 perl -e while(1){}
    1 root      15   0 10348  684  576 S  0.0  0.0   0:00.16 init [3]
    2 root      RT  -5     0    0    0 S  0.0  0.0   0:00.14 [migration/0]
    3 root      34  19     0    0    0 S  0.0  0.0   0:00.03 [ksoftirqd/0]
    4 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 [watchdog/0]
    5 root      10  -5     0    0    0 S  0.0  0.0   0:00.01 [events/0]
    6 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 [khelper]
    7 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 [kthread]

全体、もしくは一部のコアのCPU使用率が高い場合は top でどのプロセスが原因か調べる。top 起動後、「c」を押すとプログラム名ではなくコマンドラインが表示されるのでわかりやすい*12。例えば、Oracle Database は $ORACLE_HOME/bin/oracle を実行しているので、プログラム名だとサーバープロセスもバックグラウンドプロセスも oracle と表示されるが、コマンドラインにすると、ora_lgwr_orcl のように表示され、どのプロセスかわかりやすい。次に「O」を押すと、ソートする項目を選ぶことができる。ここでは「k」を押してCPU使用率が高い順にソートして表示させている。「n」ならメモリ使用量が大きい順になる。*13
デフォルトで3秒間隔で表示が更新されるが、%CPU はその3秒間に1コアを使用していた割合を表す。この例では一番上の perl ワンライナーが 99.7% となっているが、これは1コアを3秒間のほぼ占有している。

$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 2  2  60580  25848 100408 1482816    0    0   880    40    7   50  5  0 75 19  0
 4  2  60580  25600 100424 1482820    0    0 20837    36  697  489 99  1  0  0  0
 3  2  60580  31600 100436 1482820    0    0 28834    66  881  485 99  0  0  0  0
 2  2  60580  31600 100440 1482824    0    0 23909    58  771  478 100  0  0  0  0
 4  2  60580  31600 100472 1482812    0    0 38050    62 1093  501 99  1  0  0  0
 3  4  60580  31600 100476 1482836    0    0 24733    56  787  473 99  1  0  0  0
 2  7  60580  31724 100476 1482836    0    0 29248    37  891  478 99  1  0  0  0

vmstat ではまずr列とb列を見る。r列はランキューつまりCPU待ち、b列はI/O待ちのプロセス数*14。si、soの値が大きいとメモリ枯渇によりスワップが発生していると考えられる*15。bi*16、bo*17はブロックデバイスに対してI/Oを行ったブロック数。

$ mpstat -P ALL 5

10:09:48 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
10:09:53 AM  all    0.00    0.00    0.00   11.67    0.00    0.00    0.10   88.24    177.84
10:09:53 AM    0    0.00    0.00    0.00   23.35    0.00    0.00    0.20   76.45    169.66
10:09:53 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00      8.18

10:09:53 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
10:09:58 AM  all    0.00    0.00    0.00   31.39    0.00    0.00    0.10   68.51    159.60
10:09:58 AM    0    0.00    0.00    0.00   62.40    0.00    0.00    0.20   37.40    150.20
10:09:58 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00      9.40

10:09:58 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
10:10:03 AM  all    0.10    0.00    0.10    1.38    0.00    0.00    0.10   98.32    167.00
10:10:03 AM    0    0.20    0.00    0.00    2.80    0.00    0.00    0.20   96.80    156.40
10:10:03 AM    1    0.00    0.00    0.20    0.00    0.00    0.00    0.00   99.80     10.60

mpstat でCPUコア別の使用率と割込みなどの情報を確認する。特定のCPUに偏りがないか見る。また、%irq、%soft を確認することで割込みでCPUを使用している割合がわかる。%irq はハードウェア割込み、%soft はソフトウェア割込み。例えば、特定のCPUで %irq の割合が高い場合は Solaris の場合、intrstat で、どのデバイスで割込みが多く発生しているか確認することができる。異常に偏りがある場合は、OSサポートベンダーに調査を依頼するなり、オープンソースなら自分でソースを追い掛けるなりすると良い。

    • 交通量が多いか(DBレイヤー)
    • 経路の途中で詰まっていないか(OSレイヤー)
    • 経路の途中で詰まっていないか(DBレイヤー)
  • 一部の処理が遅いケース
    • 交通量が多いか(OSレイヤー)
    • 交通量が多いか(DBレイヤー)
    • 経路の途中で詰まっていないか(OSレイヤー)
    • 経路の途中で詰まっていないか(DBレイヤー)

前提

  • 正確さよりわかりやすさに重点をおき、可能な限り情報をそぎ落としている。
  • Linux を前提に書いているが、考え方は他のOSでもだいたい同じ。
  • できるだけ、どの環境でも入っているコマンドを使用している。

注意

  • SystemTap、DTrace など本番環境で使うには負荷の高いコマンドも記載しています。
  • この記事に書いているコマンドは内容を理解した上で自己責任で使用してください。

宣伝

絵で見てわかるITインフラの仕組み (DB SELECTION)

絵で見てわかるITインフラの仕組み (DB SELECTION)

*1:top でも確認できる

*2:実行可能状態(TASK_RUNNING)のプロセスの数。LinuxではCPU使用中でもCPU待ちでもプロセスの状態は実行可能状態(TASK_RUNNING)になる。

*3:スリープしているがシグナルによる待機状態解除不可(TASK_UNINTERRUPTIBLE)

*4:またはスレッド

*5:I/O待ちはCPUを使っていないので厳密にはちょっと違うが、まずはざっくり行列の長さを見る。あと、LinuxではCPUを使用中のプロセスもランキューにカウントされるが、SolarisではカウントされないなどOSの実装によって異なる。

*6:マクドナルド。大阪では「マクド」と言う

*7:-eで終了時刻を指定できる。このあたりのオプションは問題が発生した時間帯を把握していて特定の範囲を指定したい場合などに使うと見やすい。

*8:OSによっては割込みも %system にカウントされる。Linux では割込みは %system ではなく、%irq(ハードウェア割込み) と %soft(ソフトウェア割込み) にカウントされる

*9:ループと言ったほうが分かりやすいかもしれない。例えば perl -e 'while(1){}' という Perl ワンライナーを実行すると1コアが100%になる。これはI/Oなどを発行せずにただCPU命令を実行しているとCPU使用率は100%になることを意味している。

*10:ハイパースレッディングのようなものを使っている場合はスレッド

*11:ただし、他のプロセスがCPUを使うと%iowaitにはカウントされなくなる。つまり、I/Oがボトルネックかどうかは %iowait だけでは判断できない。そこは vmstat の b 列で判断できるはず。後は sar とか

*12:プログラム名で表示されている状態で「c」を押すとコマンドラインになり、さらに「c」を押すとプログラム名になる。このようにある同じ操作を繰り返すことで、機能や状態のON/OFFを切り替える仕組みを「トグル」と言う

*13:「O(大文字のオー)」を押したときに画面が切り替わり、どのキーを押すとどの列でソートされるかが表示されるのでそれに従う。ちなみに「o(小文字のオー)」を押すと表示する列を選択することができる

*14:同期I/OではI/O要求を発行するとブロックされる、つまり待つが非同期は待たないので非同期I/Oではb列には表れないので、iostat などでブロックレイヤーでのIOPS、キューの長さなどを確認する必要がある

*15:メモリが枯渇していなくても使われていないとページアウトされた気がする

*16:読み込み

*17:書き込み