はじめに
サーバーが重い、けど原因がわからない、なんとかしてくれ！
といわれたとき、その場でなんとかすることはできませんが、
原因を探してなんとかする準備はできます。
CPU、メモリ、ディスク、ネット、
これらのデバイスのどれかにボトルネックがあるとして、
いわゆるインフラの立場から状況を確認します。
何を見れば良い?
状況を確認する上で、4つのデバイスに対して調査します。
Linuxにはsysstatパッケージというツールがあるらしいので、ここでは勉強のためsysstatのコマンドを使って調査します。
正常に動作しているシステムで採取されたデータを見るため、ここで例としたマシンが重いということではありません。
ここでやること
実際のsysstatのコマンドをサーバーで実行し、サーバー(ハードウェア)がどんな状態か確認します。
sysstatで使えるもの
ここで使うシステム
# cat /etc/redhat-release
CentOS Linux release 7.5.1804 (Core)
sysstatで使えるコマンド
# repoquery --list sysstat | grep bin
/usr/bin/cifsiostat
/usr/bin/iostat
/usr/bin/mpstat
/usr/bin/nfsiostat-sysstat
/usr/bin/pidstat
/usr/bin/sadf
/usr/bin/sar
/usr/bin/tapestat
バージョンにもよりますがこれらが使えるようです。
stat系は単発でとるもの、sar/sadfはこれまでとってあるデータを見るもののようです。
| 対象 | sarコマンド | 個別のコマンド |
|---|---|---|
| CPU | sar -u ALL |
mpstat |
| Memory | sar -r |
vmstat |
| SWAP |
sar -S, sar -W, sar- B
|
- |
| DISK |
sar -b, sar -d
|
iostat -x |
| NIC | sar -n DEV |
- |
ここでは以下のコマンドは出てきません。
cifsiostat、nfsiostat-sysstat、sadf、tapestat。
調査
調査の流れ
sarコマンドを使います。
sarコマンドでデータを取得する
↓
データの変化を見る
↓
取得した項目の内容を知る
↓
変化した内容の意味を知る
sar (システムアクティビティレポーター)
sar -hでどんな内容が見れるのか確認します。
# sar -V
sysstat バージョン 10.1.5
(C) Sebastien Godard (sysstat <at> orange.fr)
# sar -h
使い方: sar [ オプション ] [ <間隔> [ <回数> ] ]
主要なオプションとその結果:
-b I/O と転送率の状況
-B ページングの状態
-d ブロックデバイスの状態
-H Hugepage の利用状況
-I { <int> | SUM | ALL | XALL }
割り込み状況
-m { <キーワード> [,...] | ALL }
電源管理状態の
キーワード:
CPU CPU 周波数
FAN ファン回転数
FREQ CPU の平均周波数
IN 入力電圧
TEMP デバイス温度
USB システムに挿入されている USB デバイス
-n { <キーワード> [,...] | ALL }
ネットワークの状態
キーワード一覧:
DEV ネットワークインターフェイス
EDEV ネットワークインターフェイス (エラー)
NFS NFS クライアント
NFSD NFS サーバ
SOCK ソケット (v4)
IP IP トラフィック (v4)
EIP IP トラフィック (v4) (エラー)
ICMP ICMP トラフィック (v4)
EICMP ICMP トラフィック (v4) (エラー)
TCP TCP トラフィック (v4)
ETCP TCP トラフィック (v4) (エラー)
UDP UDP トラフィック (v4)
SOCK6 Sockets (v6)
IP6 IP トラフィック (v6)
EIP6 IP トラフィック (v6) (エラー)
ICMP6 ICMP トラフィック (v6)
EICMP6 ICMP トラフィック (v6) (エラー)
UDP6 UDP トラフィック (v6)
-q Qキューの長さとロードアベレージの状態
-r メモリ利用率の状態
-R メモリの状況
-S スワップ領域の利用状況
-u [ ALL ]
CPU 利用の利用状況
-v カーネルのテーブル状態
-w タスクの作成とシステムスイッチの状態
-W スワップの状態
-y TTY デバイスの状態
CPU
# sar -u ALL -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 CPU %usr %nice %sys %iowait %steal %irq %soft %guest %gnice %idle
01時00分01秒 all 10.99 0.00 6.87 0.04 0.00 0.00 0.06 0.00 0.00 82.04
02時00分01秒 all 10.93 0.00 6.94 0.04 0.00 0.00 0.06 0.00 0.00 82.04
03時00分01秒 all 11.37 0.00 7.26 0.06 0.00 0.00 0.06 0.00 0.00 81.26
04時00分01秒 all 11.89 0.00 7.98 0.05 0.00 0.00 0.06 0.00 0.00 80.02
05時00分01秒 all 12.34 0.00 8.32 0.05 0.00 0.00 0.06 0.00 0.00 79.23
06時00分02秒 all 13.84 0.00 9.57 0.07 0.00 0.00 0.07 0.00 0.00 76.45
07時00分01秒 all 15.75 0.00 11.18 0.15 0.00 0.00 0.08 0.00 0.00 72.85
08時00分01秒 all 20.15 0.00 14.35 0.22 0.00 0.00 0.10 0.00 0.00 65.18
09時00分01秒 all 24.00 0.00 17.20 0.33 0.00 0.00 0.12 0.00 0.00 58.35
10時00分01秒 all 26.67 0.00 19.38 0.40 0.00 0.00 0.14 0.00 0.00 53.40
11時00分01秒 all 28.12 0.00 20.57 0.39 0.00 0.00 0.15 0.00 0.00 50.77
12時00分01秒 all 29.39 0.00 21.51 0.43 0.00 0.00 0.16 0.00 0.00 48.51
13時00分01秒 all 28.66 0.00 20.43 0.35 0.00 0.00 0.15 0.00 0.00 50.41
14時00分01秒 all 27.92 0.00 19.74 0.31 0.00 0.00 0.14 0.00 0.00 51.88
15時00分01秒 all 29.05 0.00 20.44 0.32 0.00 0.00 0.15 0.00 0.00 50.04
16時00分01秒 all 29.36 0.00 20.88 0.36 0.00 0.00 0.16 0.00 0.00 49.23
17時00分01秒 all 27.11 0.00 19.12 0.37 0.00 0.00 0.14 0.00 0.00 53.26
18時00分01秒 all 22.04 0.00 15.28 0.35 0.00 0.00 0.11 0.00 0.00 62.22
19時00分01秒 all 17.50 0.00 11.62 0.22 0.00 0.00 0.09 0.00 0.00 70.57
20時00分01秒 all 13.85 0.00 8.69 0.11 0.00 0.00 0.07 0.00 0.00 77.29
21時00分01秒 all 15.01 0.00 14.98 0.06 0.00 0.00 0.17 0.00 0.00 69.78
22時00分01秒 all 13.83 0.00 14.17 0.04 0.00 0.00 0.17 0.00 0.00 71.79
23時00分01秒 all 10.86 0.00 6.57 0.07 0.00 0.00 0.06 0.00 0.00 82.44
平均値: all 19.59 0.00 14.04 0.21 0.00 0.00 0.11 0.00 0.00 66.05
このシステムは%usrという値が7:00頃から12:00頃まで上がり、16:00頃までピークが続いたあと20:00頃に落ち着くようです。
あわせて%sys、%iowait、%softが上昇し、逆に%idleが減っています。
manのgoogle翻訳(2019/9/10 現在)
| 項目 | 説明 |
|---|---|
| %usr | ユーザーレベル（アプリケーション）で実行中に発生したCPU使用率。このフィールドには、仮想プロセッサの実行に費やされた時間は含まれないことに注意してください。 |
| %nice | 適切な優先度でユーザーレベルで実行中に発生したCPU使用率の割合。 |
| %sys | システムレベル（カーネル）で実行中に発生したCPU使用率。このフィールドには、ハードウェアおよびソフトウェア割り込みの処理に費やされた時間が含まれていることに注意してください。 |
| %iowait | 1つまたは複数のCPUがアイドル状態であった間にシステムに未処理のディスクI/O要求があった時間の割合。 |
| %steal | ハイパーバイザーが別の仮想プロセッサーにサービスを提供している間に、1つまたは複数の仮想CPUが不本意に待機した時間の割合。 |
| %irq | CPUがハードウェア割り込みの処理に費やした時間の割合。 |
| %soft | 1つまたは複数のCPUがソフトウェア割り込みの処理に費やした時間の割合。 |
| %guest | 1つまたは複数のCPUが仮想プロセッサを実行するために費やした時間の割合。 |
| %idle | 1つまたは複数のCPUがアイドル状態で、システムに未処理のディスクI/O要求がなかった時間の割合。 |
このシステムは7:00から負荷が増え始め、10:00-16:00がピークとなり、21:00に負荷が収まっています。
日中に負荷が高くなるシステムと思われます。
CPUの使用率100%と考えると1コアあたり10%になり、12:00頃は29.39%で3CPU近く使い切っていることになります。
CPUの各コアが使い切っているか、mpstatを使って確認します。
# mpstat -P ALL
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月11日 _x86_64_ (10 CPU)
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月11日 _x86_64_ (12 CPU)
12時13分12秒 CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
12時13分12秒 all 15.67 0.00 10.69 0.36 0.00 0.09 0.00 0.00 0.00 73.20
12時13分12秒 0 15.57 0.00 10.04 0.32 0.00 0.14 0.00 0.00 0.00 73.92
12時13分12秒 1 18.17 0.00 11.81 0.43 0.00 0.11 0.00 0.00 0.00 69.48
12時13分12秒 2 17.26 0.00 11.63 0.41 0.00 0.09 0.00 0.00 0.00 70.61
12時13分12秒 3 16.47 0.00 11.15 0.39 0.00 0.09 0.00 0.00 0.00 71.90
12時13分12秒 4 15.93 0.00 10.92 0.36 0.00 0.08 0.00 0.00 0.00 72.71
12時13分12秒 5 15.38 0.00 10.71 0.35 0.00 0.08 0.00 0.00 0.00 73.48
12時13分12秒 6 15.25 0.00 10.51 0.34 0.00 0.08 0.00 0.00 0.00 73.83
12時13分12秒 7 14.83 0.00 10.44 0.34 0.00 0.06 0.00 0.00 0.00 74.33
12時13分12秒 8 15.55 0.00 10.42 0.33 0.00 0.07 0.00 0.00 0.00 73.63
12時13分12秒 9 14.68 0.00 10.36 0.33 0.00 0.07 0.00 0.00 0.00 74.56
12時13分12秒 10 14.44 0.00 10.24 0.32 0.00 0.07 0.00 0.00 0.00 74.94
12時13分12秒 11 14.47 0.00 10.12 0.33 0.00 0.08 0.00 0.00 0.00 75.00
12:13時点ではそれぞれバランス良く使っているように見えるので、日中のCPU負荷も同じ傾向と考えると、まだ余裕がありそうです。
どんなアプリケーションがCPUを使っているかは上のレイヤーになるのでここでは確認しません。
Memory
物理メモリ領域、スワップ領域を対象に確認します。
物理メモリ領域
sarは2種類確認できるようです。
-r メモリ利用率の状態
-R メモリの状況
sar -r
# sar -r -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 kbmemfree kbmemused %memused kbbuffers kbcached kbcommit %commit kbactive kbinact kbdirty
01時00分01秒 10368804 253591624 96.07 0 202576360 16312676 6.09 203202356 3335980 60
02時00分01秒 9504168 254456260 96.40 0 203491352 16185072 6.04 204040456 3336044 308
03時00分01秒 9567936 254392492 96.38 0 203378148 16255320 6.07 204360940 2944220 528
04時00分01秒 9653024 254307404 96.34 0 203386036 16197172 6.05 204145572 3130284 60
05時00分01秒 10693216 253267212 95.95 0 202448284 16192076 6.04 202864700 3468168 1460
06時00分02秒 11051532 252908896 95.81 0 202147300 16189956 6.04 202389620 3637200 18564
07時00分01秒 11630200 252330228 95.59 0 201744116 16258508 6.07 201866036 3799712 56224
08時00分01秒 12073848 251886580 95.43 0 202076080 16280224 6.08 201875912 4125372 109096
09時00分01秒 13158320 250802108 95.02 0 201573764 16189992 6.04 201230200 4217384 154188
10時00分01秒 13713136 250247292 94.80 0 201062828 16208424 6.05 200637356 4315720 153968
11時00分01秒 14927700 249032728 94.34 0 200800928 16263692 6.07 200072912 4640680 149820
12時00分01秒 16164316 247796112 93.88 0 200891516 16400224 6.12 199070412 5840936 134896
13時00分01秒 17333088 246627340 93.43 0 200988988 16212408 6.05 198693352 6181688 161828
14時00分01秒 15433928 248526500 94.15 0 202829848 16230356 6.06 200937792 5796072 130192
15時00分01秒 11593072 252367356 95.61 0 206815944 16219708 6.06 204885516 5823156 170460
16時00分01秒 16231912 247728516 93.85 0 202460308 16479488 6.15 203515292 3061444 175904
17時00分01秒 15642080 248318348 94.07 0 203262168 16330472 6.10 205132824 2091304 124516
18時00分01秒 19417992 244542436 92.64 0 199676736 16155832 6.03 201709228 1838048 73028
19時00分01秒 20678008 243282420 92.17 0 198469068 16151964 6.03 200543728 1799252 25216
20時00分01秒 21592308 242368120 91.82 0 197580920 16173264 6.04 199700084 1756456 1896
21時00分01秒 19495192 244465236 92.61 0 197737128 16194676 6.05 199784960 1852144 2096
22時00分01秒 19078208 244882220 92.77 0 198080684 16219176 6.05 200210100 1767284 40
23時00分01秒 18507292 245453136 92.99 0 198640384 16288724 6.08 200828980 1770160 444
平均値: 14674317 249286111 94.44 0 201396473 16243018 6.06 201812971 3501248 71513
kbmemfreeは1日かけて増えていっています。
kbmemusedと%memusedが1日かけてゆるやかに減っていっています。
kbinactとkbdirtyは6:00-18:00のあいだ、13:00をピークに高くなっています。
CPUに続き、manで項目を確認します。
| 項目 | 説明 |
|---|---|
| kbmemfree | 使用可能な空きメモリの量（キロバイト単位）。 |
| kbmemused | 使用メモリの量（キロバイト単位）。これは、カーネル自体が使用するメモリを考慮していません。 |
| %memused | 使用済みメモリの割合。 |
| kbbuffers | カーネルがバッファとして使用するメモリの量（キロバイト単位）。 |
| kbcached | カーネルがデータをキャッシュするために使用するメモリの量（キロバイト単位）。 |
| kbcommit | 現在のワークロードに必要なメモリの量（キロバイト単位）。これは、メモリ不足がないことを保証するために必要なRAM /スワップの量の推定値です。 |
| %commit | メモリーの合計量（RAM +スワップ）に対する現在のワークロードに必要なメモリーの割合。カーネルは通常メモリをオーバーコミットするため、この数値は100％を超える場合があります。 |
| kbactive | アクティブなメモリの量（キロバイト単位）（最近使用され、通常は回収されていない 絶対に必要でない限り）。 |
| kbinact | 非アクティブなメモリの量（キロバイト単位）（最近はあまり使用されていません。の資格がある 他の目的のために再生されます）。 |
| kbdirty | 書き込みを待機しているメモリの量（キロバイト） ディスクに戻ります。 |
最後の3つはRHEL7で追加された項目のようです。
1日かけてメモリの使用量が減っていっているようです。
利用率は96%と高い値になっていますが、必要とされているメモリ自体は6%台を推移しているため、オーバースペックのような気もします。
バッファとキャッシュ、コミットがいまいちわかりません。
vmstat、freeで見れる値と一致しているか確認します。
$ sar -r 0 ; vmstat ; free
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月11日 _x86_64_ (12 CPU)
12時20分27秒 kbmemfree kbmemused %memused kbbuffers kbcached kbcommit %commit kbactive kbinact kbdirty
12時20分27秒 16877068 247083360 93.61 0 201600556 16164572 6.03 198966556 6502784 39768
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
2 0 2992948 16877200 0 232606752 0 2 5 367 0 0 16 11 73 0 0
total used free shared buff/cache available
Mem: 263960428 14476736 16876944 3312300 232606748 234044264
Swap: 3907580 2992948 914632
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月11日 _x86_64_ (10 CPU)
09時40分01秒 kbmemfree kbmemused %memused kbbuffers kbcached kbcommit %commit kbactive kbinact kbdirty
09時40分01秒 9546256 56262292 85.49 0 31453520 15710416 22.53 20778924 14870092 5480
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
7 0 108032 9546580 0 51112872 0 0 0 132 0 0 18 13 68 1 0
total used free shared buff/cache available
Mem: 65808548 5149500 9546176 3328880 51112872 52251840
Swap: 3907580 108032 3799548
コミットについてはこちらのページで理解できました。
%commit の高騰とオーバーコミットについて(tech-lab.sios.jp)
実際に使用しているメモリの情報は以下で説明されていました。
sarコマンドの結果からメモリの負荷を見る(bose999.hatenablog.com)
図解しているページを確認します。
【RHEL】linuxメモリのfreeとmeminfoの関係を図解し利用率の計算方法を説明してみる(nopipi.hatenablog.com)
図解はsarとvmstatの結果がないので、照合しながらsar/vmstatの値を読み解きます。
kbmemfree(sar) + kbmemused(sar)
16,877,068 + 247,083,360 = 263,960,428
Mem:total(free)と一致します。(*1)
sarでいうkbmemusedは、freeでいうusedではないようです。
%memusedは、freeコマンドのMem:totalに対するkbmemusedの割合を表しているようです。
memory/free(vmstat) + memory/buffer(vmstat) + memory/cached(vmstat)
16,877,200 + 0 + 232,606,752 = 249,483,952
コマンドの実行時間が若干ずれているので断言できませんが、
freeコマンドのMem:totalからvmstatコマンドのfree/buffer/cacheを引いた値がfreeコマンドのUsedになるようです。
Mem:total(free) - (memory/free + buffer + cached(いずれもvmstat) )
263,960,428 - 249,483,952 = 14,476,476
このシステムでは、物理totalが264.0GB、物理メモリ空き容量が16.9GB、メモリ使用量が247.1GB、cached使用量が232.6GB、実際の使用量(*2)が14.5GBとなるようです。
メモリの使用量のうち、メモリ解放できる(スワップアウトできる量)は一体どうなっているのでしょう…
なお%comimtはSWAPも含めた容量に対して計算されているようでした。(計算は割愛)
kbcommitは16,164,572で16.2GB必要となっていますが、実際には14.5GBしか使っていないようです。
とりあえずkbmemfreeが16.9GBあること、実際の使用量は14.5GB、%memusedと%commitが100%を超えていないので大丈夫でしょう。
sar -R
# sar -R -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 frmpg/s bufpg/s campg/s
01時00分01秒 53.71 0.00 -60.15
02時00分01秒 -60.04 0.00 63.54
03時00分01秒 4.43 0.00 -7.86
04時00分01秒 5.91 0.00 0.55
05時00分01秒 72.24 0.00 -65.12
06時00分02秒 24.88 0.00 -20.90
07時00分01秒 40.19 0.00 -28.01
08時00分01秒 30.81 0.00 23.05
09時00分01秒 75.32 0.00 -34.89
10時00分01秒 38.53 0.00 -35.48
11時00分01秒 84.33 0.00 -18.19
12時00分01秒 85.88 0.00 6.29
13時00分01秒 81.16 0.00 6.77
14時00分01秒 -131.91 0.00 127.86
15時00分01秒 -266.69 0.00 276.77
16時00分01秒 322.17 0.00 -302.50
17時00分01秒 -40.96 0.00 55.68
18時00分01秒 262.27 0.00 -249.04
19時00分01秒 87.50 0.00 -83.87
20時00分01秒 63.49 0.00 -61.67
21時00分01秒 -145.63 0.00 10.85
22時00分01秒 -28.95 0.00 23.86
23時00分01秒 -39.66 0.00 38.88
平均値: 26.91 0.00 -14.50
frmpg/s、campg/sともに時間軸では規則性がないように感じられます。
bufpg/sは0のままです。
翻訳を見ていきます。
| 項目 | 内容 |
|---|---|
| frmpg/s | 1秒あたりにシステムによって解放されたメモリページの数。負の値は、システムによって割り当てられたページ数を表します。マシンのアーキテクチャに応じて、ページのサイズは4 kBまたは8 kBであることに注意してください。 |
| bufpg/s | システムがバッファとして使用する1秒あたりの追加メモリページの数。負の値は、システムがバッファとして使用するページが少ないことを意味します。 |
| campg/s | システムによってキャッシュされる1秒あたりの追加メモリページの数。負の値は、キャッシュ内のページが少ないことを意味します。 |
# getconf PAGE_SIZE
4096
ページサイズは4KBなので、容量に換算するとそれぞれ4倍の値になるようです。
CPU負荷が高まる時間帯に、システムにページが割り当てられているように思われます。
SWAP領域
sar -S
スワップ領域の利用状況
# sar -S -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 kbswpfree kbswpused %swpused kbswpcad %swpcad
01時00分01秒 857032 3050548 78.07 286828 9.40
02時00分01秒 857032 3050548 78.07 286828 9.40
03時00分01秒 857032 3050548 78.07 286828 9.40
04時00分01秒 856776 3050804 78.07 286828 9.40
05時00分01秒 857032 3050548 78.07 286828 9.40
06時00分02秒 857032 3050548 78.07 286832 9.40
07時00分01秒 856776 3050804 78.07 286828 9.40
08時00分01秒 854984 3052596 78.12 286880 9.40
09時00分01秒 854472 3053108 78.13 286904 9.40
10時00分01秒 854728 3052852 78.13 286952 9.40
11時00分01秒 853960 3053620 78.15 287512 9.42
12時00分01秒 842952 3064628 78.43 287156 9.37
13時00分01秒 844488 3063092 78.39 287324 9.38
14時00分01秒 848840 3058740 78.28 287332 9.39
15時00分01秒 850120 3057460 78.24 287476 9.40
16時00分01秒 849864 3057716 78.25 287616 9.41
17時00分01秒 850376 3057204 78.24 291148 9.52
18時00分01秒 908744 2998836 76.74 284060 9.47
19時00分01秒 908640 2998940 76.75 284052 9.47
20時00分01秒 909256 2998324 76.73 284052 9.47
21時00分01秒 909256 2998324 76.73 284068 9.47
22時00分01秒 909000 2998580 76.74 284052 9.47
23時00分01秒 908744 2998836 76.74 284052 9.47
平均値: 867702 3039878 77.79 286453 9.42
どの値もほとんどかわっていません。
manの翻訳。
| 項目 | 内容 |
|---|---|
| kbswpfree | キロバイト単位の空きスワップ領域。 |
| kbswpused | 使用済みスワップスペースの量（キロバイト単位）。 |
| %swpused | 使用済みスワップスペースの割合。 |
| kbswpcad | キャッシュされたスワップメモリの量（キロバイト単位）。これは、一度スワップアウトされてスワップインされたメモリですが、スワップ領域にも存在します（メモリが必要な場合は、スワップ領域に既にあるので再度スワップアウトする必要はありません。これによりI/Oが節約されます。 ）。 |
| %swpcad | 使用済みスワップスペースの量に対するキャッシュスワップメモリの割合。 |
負荷が低くなる18:00にswapの使用量が若干減るようです。
sar -W
# sar -W -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 pswpin/s pswpout/s
01時00分01秒 0.00 0.00
02時00分01秒 0.00 0.00
03時00分01秒 0.00 0.00
04時00分01秒 0.02 0.36
05時00分01秒 0.13 0.57
06時00分02秒 0.32 0.36
07時00分01秒 0.08 0.68
08時00分01秒 1.45 25.29
09時00分01秒 3.69 64.32
10時00分01秒 5.29 116.85
11時00分01秒 3.52 77.41
12時00分01秒 7.08 48.99
13時00分01秒 5.44 229.35
14時00分01秒 2.47 111.26
15時00分01秒 0.79 78.84
16時00分01秒 4.50 144.05
17時00分01秒 1.98 40.47
18時00分01秒 3.10 11.73
19時00分01秒 0.75 2.08
20時00分01秒 0.48 3.96
21時00分01秒 0.01 0.29
22時00分01秒 0.05 0.35
23時00分01秒 0.04 0.21
平均値: 1.79 41.63
割合は違いますが、pswpin/sとpswout/sは負荷に合わせて増えています。
翻訳。
| 項目 | 内容 |
|---|---|
| pswpin/s | システムが1秒間に持ち込んだスワップページの総数。 |
| pswpout/s | システムが1秒あたりに取り出したスワップページの総数。 |
負荷が増えるとSWAPの取り出しがあるようです。
ディスク
sar -b
sar -b -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 tps rtps wtps bread/s bwrtn/s
01時00分01秒 171.05 0.50 170.55 6.47 3321.22
02時00分01秒 172.15 0.13 172.02 3.12 2835.67
03時00分01秒 183.32 0.18 183.14 4.06 3008.28
04時00分01秒 206.16 0.53 205.63 8.69 3473.30
05時00分01秒 230.27 0.96 229.31 14.59 3787.59
06時00分02秒 300.41 1.18 299.23 20.23 5191.45
07時00分01秒 432.22 1.72 430.51 27.29 7359.05
08時00分01秒 650.66 3.46 647.20 59.89 11400.96
09時00分01秒 842.35 5.17 837.18 99.51 15196.77
10時00分01秒 999.21 6.18 993.03 125.66 18628.16
11時00分01秒 1061.55 6.08 1055.47 119.46 19569.56
12時00分01秒 1095.46 6.63 1088.83 149.56 20044.35
13時00分01秒 1072.05 6.94 1065.11 140.03 20899.11
14時00分01秒 1035.95 5.10 1030.85 113.25 19484.81
15時00分01秒 1093.11 4.51 1088.60 99.61 20402.80
16時00分01秒 1119.38 6.30 1113.07 145.38 21448.18
17時00分01秒 1028.21 3.72 1024.50 86.38 18765.51
18時00分01秒 781.74 3.87 777.87 89.58 13888.07
19時00分01秒 530.48 2.63 527.85 47.49 9232.47
20時00分01秒 357.19 1.60 355.59 30.61 6199.57
21時00分01秒 383.48 32.56 350.92 1037.14 7623.04
22時00分01秒 210.95 0.71 210.24 15.97 3899.19
23時00分01秒 176.98 0.69 176.29 11.08 3133.38
平均値: 614.54 4.41 610.13 106.74 11251.86
7:00-18:00にかけてtps、wtps、bwrtn/s、bwrtn/sが多くなっています。
| 項目 | 内容 |
|---|---|
| tps | 物理デバイスに発行された1秒あたりの転送の総数。転送は、物理デバイスへのI/O要求です。複数の論理要求は、デバイスへの単一のI/O要求に結合できます。転送のサイズは不定です。 |
| rtps | 物理デバイスに発行された1秒あたりの読み取り要求の総数。 |
| wtps | 物理デバイスに発行された1秒あたりの書き込み要求の総数。 |
| bread/s | 1秒あたりのブロック数でデバイスから読み取られたデータの合計量。ブロックは2.4カーネル以降のセクターに相当するため、サイズは512バイトです。古いカーネルでは、ブロックのサイズは不定です。 |
| bwrtn/s | 1秒あたりのブロック数でデバイスに書き込まれたデータの合計量。 |
CPU負荷が高まるにつれ、物理デバイスへI/O要求が増えるようです。
同時にWriteも多くなっています。
21:00頃読み取りが発生していますが、ほとんどライト中心のディスクアクセスのようです。
sar -B
sar -B -f /var/log/sa/sa10 -t 3600
Linux 3.10.0-862.14.4.el7.x86_64 (test) 2019年09月10日 _x86_64_ (12 CPU)
00時00分01秒 pgpgin/s pgpgout/s fault/s majflt/s pgfree/s pgscank/s pgscand/s pgsteal/s %vmeff
01時00分01秒 3.24 1660.61 98912.63 0.00 72023.28 0.01 0.00 0.01 100.00
02時00分01秒 1.56 1417.84 98668.34 0.00 71608.89 0.00 0.00 0.00 0.00
03時00分01秒 2.03 1504.14 100489.03 0.00 72739.29 0.09 0.00 0.09 99.12
04時00分01秒 4.34 1736.65 101948.65 0.01 73939.07 0.89 0.16 0.80 76.07
05時00分01秒 7.30 1893.79 107587.52 0.02 76429.54 2.03 0.32 1.67 70.84
06時00分02秒 10.11 2595.72 119108.96 0.04 84228.28 2.49 0.36 2.12 74.26
07時00分01秒 13.64 3679.52 142235.00 0.02 96372.53 3.65 0.25 2.51 64.23
08時00分01秒 29.95 5700.48 179784.53 0.25 117304.67 16.83 1.08 11.98 66.90
09時00分01秒 49.75 7598.39 213195.13 0.56 136255.06 30.60 0.80 22.12 70.45
10時00分01秒 62.83 9314.08 237679.84 0.81 148692.15 45.14 0.25 33.64 74.11
11時00分01秒 59.73 9784.78 247786.55 0.55 154177.77 31.52 0.48 22.27 69.58
12時00分01秒 74.78 10022.52 255322.10 1.00 158183.58 41.67 2.32 23.33 53.02
13時00分01秒 70.01 10449.21 240571.77 0.89 155300.84 67.18 0.92 55.14 80.96
14時00分01秒 56.63 9742.40 238913.24 0.37 150568.44 28.00 0.40 22.62 79.63
15時00分01秒 49.80 10201.40 255451.44 0.13 157776.61 17.54 0.15 15.15 85.61
16時00分01秒 72.69 10724.09 256859.48 0.67 160748.47 37.22 1.52 29.77 76.86
17時00分01秒 43.19 9382.75 242660.94 0.29 152946.18 15.43 0.09 10.95 70.52
18時00分01秒 44.79 6944.03 199926.37 0.42 129587.72 21.95 0.00 8.94 40.71
19時00分01秒 23.74 4616.24 155047.55 0.10 108324.78 12.91 0.00 4.23 32.81
20時00分01秒 15.31 3099.78 122888.04 0.06 91947.53 9.74 0.00 2.98 30.65
21時00分01秒 518.57 3811.52 528042.93 0.00 193247.44 1.24 0.00 0.37 29.66
22時00分01秒 7.99 1949.60 518003.34 0.01 186348.74 2.38 0.00 0.67 27.95
23時00分01秒 5.54 1566.69 98029.25 0.01 72335.92 2.37 0.00 0.87 36.67
平均値: 53.37 5625.93 206920.97 0.27 122656.76 17.00 0.40 11.84 68.05
sar -bのリードと同じ傾向がpgscand/sを除くすべてで見られます。
| 項目 | 内容 |
|---|---|
| pgpgin/s | 1秒あたりにシステムがディスクからページインした合計キロバイト数。注：古いカーネル（2.2.x）では、この値は1秒あたりのブロック数です（キロバイトではありません）。 |
| pgpgout/s | システムが1秒あたりにディスクにページアウトした合計キロバイト数。注：古いカーネル（2.2.x）では、この値は1秒あたりのブロック数です（キロバイトではありません）。 |
| fault/s | システムによって1秒あたりに発生したページフォールト（メジャー+マイナー）の数。一部のページフォールトはI / Oなしで解決できるため、これはI / Oを生成するページフォールトのカウントではありません。 |
| majflt/s | システムが1秒あたりに行った重大な障害（ディスクからメモリページをロードする必要がある障害）の数。 |
| pgfree/s | システムによって1秒あたりに空きリストに配置されるページの数。 |
| pgscank/s | kswapdデーモンによってスキャンされた1秒あたりのページ数。 |
| pgscand/s | 1秒あたりに直接スキャンされるページの数。 |
| pgsteal/s | メモリ需要を満たすためにシステムがキャッシュ（pagecacheおよびswapcache）から1秒あたりに回収したページ数。 |
| %vmeff | pgsteal / pgscanとして計算され、これはページ再利用の効率の指標です。100％に近い場合、非アクティブリストの末尾にあるほとんどすべてのページが刈り取られています。低くなりすぎると（30％未満など）、仮想メモリに問題が発生します。一定時間内にページがスキャンされなかった場合、このフィールドはゼロとして表示されます。 |
ページフォルトにはメジャーとマイナーがあるようです。メジャーフォールトの場合、読み出す必要があるもののためフエルトパフォーマンスに影響するようです。12:00をピークににメジャーフォールトが発生しており、ページ再利用の効率が53.02%と前後と比べて若干低くなっています。
kswapd-> Kernel Swap Daemon により、4:40-5:00にスキャンされているページと回収されている(物理メモリに戻した?)量が非常に多くなっています。
sar -d
sar -d -f /var/log/sa/sa10 -t 3600 | grep -E "DEV|dev8-16"
00時00分01秒 DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
01時00分01秒 dev8-16 153.49 2.89 2323.10 15.15 0.57 3.73 0.07 1.08
02時00分01秒 dev8-16 155.88 2.63 2378.18 15.27 0.60 3.82 0.08 1.17
03時00分01秒 dev8-16 165.85 3.32 2516.54 15.19 0.63 3.83 0.08 1.25
04時00分01秒 dev8-16 187.19 7.61 2933.69 15.71 0.68 3.64 0.07 1.28
05時00分01秒 dev8-16 208.00 12.17 3195.49 15.42 0.74 3.56 0.07 1.36
06時00分02秒 dev8-16 269.74 15.17 4365.95 16.24 0.93 3.43 0.07 1.86
07時00分01秒 dev8-16 386.89 22.21 6253.35 16.22 1.45 3.75 0.07 2.87
08時00分01秒 dev8-16 581.03 40.25 9500.98 16.42 2.31 3.98 0.08 4.43
09時00分01秒 dev8-16 747.77 55.32 12354.82 16.60 3.06 4.09 0.08 6.09
10時00分01秒 dev8-16 876.36 70.27 14816.99 16.99 3.56 4.07 0.09 7.46
11時00分01秒 dev8-16 923.75 78.53 15684.95 17.06 3.72 4.03 0.09 8.34
12時00分01秒 dev8-16 955.21 82.01 16313.21 17.16 3.86 4.04 0.09 8.60
13時00分01秒 dev8-16 942.84 84.14 16026.88 17.09 3.81 4.04 0.09 8.15
14時00分01秒 dev8-16 912.43 78.76 15641.23 17.23 3.67 4.02 0.09 7.91
15時00分01秒 dev8-16 959.17 78.48 16598.03 17.39 4.01 4.18 0.09 8.57
16時00分01秒 dev8-16 975.18 97.34 16910.12 17.44 3.83 3.93 0.09 8.47
17時00分01秒 dev8-16 900.95 60.71 15364.81 17.12 4.28 4.75 0.09 8.44
18時00分01秒 dev8-16 692.48 57.57 11606.35 16.84 2.96 4.28 0.08 5.51
19時00分01秒 dev8-16 472.22 38.48 7783.26 16.56 1.89 4.01 0.07 3.31
20時00分01秒 dev8-16 317.04 24.25 5184.21 16.43 1.15 3.63 0.07 2.08
21時00分01秒 dev8-16 354.71 1035.91 6694.69 21.79 1.44 4.05 0.22 7.77
22時00分01秒 dev8-16 189.42 14.52 3111.86 16.50 0.62 3.27 0.06 1.14
23時00分01秒 dev8-16 160.20 10.19 2667.87 16.72 0.59 3.70 0.07 1.11
平均値: dev8-16 542.95 85.77 9140.29 16.99 2.19 4.03 0.09 4.71
svctmを除いて、CPU負荷と同じような傾向にあるようです。
翻訳。
| 項目 | 内容 |
|---|---|
| tps | デバイスに発行された1秒あたりの転送数を示します。複数の論理要求は、デバイスへの単一のI / O要求に結合できます。転送のサイズは不定です。 |
| rd_sec/s | デバイスから読み取られたセクターの数。セクターのサイズは512バイトです。 |
| wr_sec/s | デバイスに書き込まれたセクターの数。セクターのサイズは512バイトです。 |
| avgrq-sz | デバイスに発行された要求の平均サイズ（セクター単位）。 |
| avgqu-sz | デバイスに発行されたリクエストの平均キュー長。 |
| await | サービス対象のデバイスに発行されたI / O要求の平均時間（ミリ秒）。これには、キュー内のリクエストに費やされた時間とそれらのサービスに費やされた時間が含まれます。 |
| svctm | デバイスに発行されたI / O要求の平均サービス時間（ミリ秒）。 |
| %util | I / O要求がデバイスに発行されたCPU時間の割合（デバイスの帯域幅使用率）。この値が100％に近い場合、デバイスの飽和が発生します。 |
以下のリンク先の説明で理解しました。
Linux の iostat の出力結果を銀行のATMに例えて説明してみる(yohei-a.hatenablog.jp)
iostat await svctm の 見かた、考え方(www.slideshare.net/shibataayumu)
デバイス側のIO処理時間は良好で、負荷によりawaitが極端に大きくなっていない、デバイスの帯域幅使用率も低めなので、IOは問題なさそうです。
ネットワーク
sar -n DEV
通常はSSHで入って調査すると思いますので、コマンドで調査しようとしている時点で問題はないのかと思います。
sar -n DEV -f /var/log/sa/sa10 -t 3600 | grep -E "IFACE|ens224"
00時00分01秒 IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s
01時00分01秒 ens224 742.89 546.72 1320.76 19022.22 0.00 0.00 0.00
02時00分01秒 ens224 734.34 550.95 1315.02 19146.51 0.00 0.00 0.00
03時00分01秒 ens224 739.32 547.47 1321.39 19099.02 0.00 0.00 0.00
04時00分01秒 ens224 734.33 550.81 1336.60 19152.19 0.00 0.00 0.00
05時00分01秒 ens224 744.33 556.02 1325.89 18996.85 0.00 0.00 0.00
06時00分02秒 ens224 763.99 574.82 1386.84 19062.54 0.00 0.00 0.00
07時00分01秒 ens224 793.73 602.46 1426.91 18961.90 0.00 0.00 0.00
08時00分01秒 ens224 822.04 635.01 1506.23 18526.99 0.00 0.00 0.00
09時00分01秒 ens224 865.85 680.23 1607.16 18402.37 0.00 0.00 0.00
10時00分01秒 ens224 904.24 728.91 1688.82 18079.84 0.00 0.00 0.00
11時00分01秒 ens224 933.76 758.21 1729.67 18127.74 0.00 0.00 0.00
12時00分01秒 ens224 943.41 762.59 1771.13 18086.88 0.00 0.00 0.00
13時00分01秒 ens224 922.52 744.54 1746.04 18172.47 0.00 0.00 0.00
14時00分01秒 ens224 922.26 746.77 1729.02 18222.92 0.00 0.00 0.00
15時00分01秒 ens224 935.81 755.45 1739.54 17940.49 0.00 0.00 0.00
16時00分01秒 ens224 950.90 769.57 1757.63 18063.91 0.00 0.00 0.00
17時00分01秒 ens224 928.95 747.74 1739.35 18366.19 0.00 0.00 0.00
18時00分01秒 ens224 863.99 681.03 1614.33 18442.60 0.00 0.00 0.00
19時00分01秒 ens224 819.22 626.88 1510.68 18886.78 0.00 0.00 0.00
20時00分01秒 ens224 783.42 596.46 1448.02 19124.75 0.00 0.00 0.00
21時00分01秒 ens224 771.67 574.14 1378.71 19114.47 0.00 0.00 0.00
22時00分01秒 ens224 761.80 565.06 1344.08 19211.95 0.00 0.00 0.00
23時00分01秒 ens224 744.69 553.65 1328.84 19166.94 0.00 0.00 0.00
平均値: ens224 831.63 645.89 1524.90 18668.63 0.00 0.00 0.00
rxpck/s、txpck/s、が負荷に合わせて増減しています。
翻訳をみてみます。
| 項目 | 内容 |
|---|---|
| rxpck/s | 1秒あたりに受信されたパケットの総数。 |
| txpck/s | 1秒あたりに送信されたパケットの総数。 |
| rxkB/s | 1秒あたりの受信キロバイト数の合計。 |
| txkB/s | 1秒あたりに送信されたキロバイトの総数。 |
| rxcmp/s | 1秒あたりに受信した圧縮パケットの数（cslipなどの場合）。 |
| txcmp/s | 1秒あたりに送信された圧縮パケットの数。 |
| rxmcst/s | 1秒あたりに受信したマルチキャストパケットの数。 |
負荷にあわせて送受信のデータが増減しています。
NICのリンクスピードが落ちているというようなこともなさそうです。
通常はSSH接続で中を見ると思うのでNIC周りの故障はほとんどどないかと思います。
$ sar -n EDEV -f /var/log/sa/sa10 -t 3600 | grep -E "IFACE|ens224"
00時00分01秒 IFACE rxerr/s txerr/s coll/s rxdrop/s txdrop/s txcarr/s rxfram/s rxfifo/s txfifo/s
01時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
02時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
03時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
04時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
05時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06時00分02秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
07時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
08時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
09時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
10時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
11時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
12時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
13時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
14時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
15時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
16時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
17時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
18時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
19時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
20時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
21時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
22時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
23時00分01秒 ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
平均値: ens224 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
すべてゼロ。
| 項目 | 内容 |
|---|---|
| rxerr/s | 1秒あたりに受信した不良パケットの総数。 |
| txerr/s | パケットの送信中に1秒あたりに発生したエラーの総数。 |
| coll/s | パケットの送信中に1秒あたりに発生した衝突の数。 |
| rxdrop/s | Linuxバッファーのスペース不足のために1秒あたりにドロップされた受信パケットの数。 |
| txdrop/s | Linuxバッファーのスペース不足のために1秒あたりにドロップされた送信パケットの数。 |
| txcarr/s | パケットの送信中に1秒あたりに発生したキャリアエラーの数。 |
| rxfram/s | 受信パケットで1秒あたりに発生したフレームアライメントエラーの数。 |
| rxfifo/s | 受信パケットで1秒あたりに発生したFIFOオーバーランエラーの数。 |
| txfifo/s | 送信パケットで1秒あたりに発生したFIFOオーバーランエラーの数。 |
バッファ溢れもないようです。
*1
manのカーネルが使うメモリは考慮しません…という表現を信じるなら、kbemmfree + kbmemused(ユーザー空間) + なにか = Totalになるはずですが、今回の計算では「なにか」は 0 になってしまいました。
kbmemusedにはカーネル空間もないと計算がおかしい気がします。
*2
実際の使用量、としましたがバッファとキャッシュを除いた使用量のことです。
まとめ
日頃からトラブルシューティングに使えるコマンドに慣れておく・使っていろいろな種類のサーバーの傾向を知っておくのが大事ですね。