【実践】障害切り分け ~LoadAverage編~

雑談

どうも梶松です。

今回は私の業務の1つである障害対応について記載していきます。

その中でも切り分けが必須であるLoad Avarageにスコープを当てて記載をしていきます。


  • 本記事から会得できること
    • LoadAverageとは
    • LoadAvarageの正常値
    • LoadAvarage上昇の原因調査

  • 結論

   LoadAvarageはどうしようもないので負荷が下がるまで待つ!!!

梶松先生の次回作にご期待ください!!!

嘘ですw
もう少し説明しますね。

  • LoadAverageとは
top - 01:02:27 up 4 min, 6 users, load average: 2889.63, 638.35, 208.89
Tasks: 14966 total, 384 running, 14371 sleeping, 0 stopped, 211 zombie
%Cpu(s): 1.7 us, 85.0 sy, 0.0 ni, 1.6 id, 3.3 wa, 0.0 hi, 8.4 si, 0.0 st
KiB Mem : 4912064 total, 298100 free, 3781500 used, 832464 buff/cache
KiB Swap: 839676 total, 152160 free, 687516 used. 202460 avail Mem

20956 root 20 0 116372 964 0 D 8.0 0.0 0:00.53 bash
23974 root 20 0 116372 1116 0 D 7.7 0.0 0:00.56 bash
5830 root 20 0 189184 28000 1140 R 6.9 0.6 0:01.82 top
23041 root 20 0 116372 1112 0 D 6.6 0.0 0:00.45 bash
20508 root 20 0 116372 1328 176 R 3.3 0.0 0:00.22 bash
22759 root 20 0 116372 1100 0 D 3.2 0.0 0:00.23 bash
24210 root 20 0 116372 1212 164 D 2.9 0.0 0:00.19 bash
30082 root 20 0 116372 1156 0 D 2.1 0.0 0:00.14 bash
22318 root 20 0 116372 1112 0 D 2.0 0.0 0:00.13 bash
30126 root 20 0 116372 1304 164 D 2.0 0.0 0:00.13 bash
20634 root 20 0 116372 99m6 0 D 1.8 0.0 0:00.18 bash
21467 root 20 0 116372 1284 156 D 1.7 0.0 0:00.11 bash
22333 root 20 0 116372 1320 180 D 1.7 0.0 0:00.16 bash
21829 root 20 0 116372 1044 0 D 1.5 0.0 0:00.10 bash
31354 root 20 0 116372 1280 168 D 1.5 0.0 0:00.10 bash
21451 root 20 0 116372 1028 0 D 1.4 0.0 0:00.09 bash
22635 root 20 0 116372 1064 0 D 1.4 0.0 0:00.12 bash

運用しているシステムがこの例のようになった場合はどうしようもありません。
もはや操作すら受け付けないので電源ぶち抜くしかありませんね。
もしくわ、本当に下がるまで待つぐらい
ここまで来たらいくら待っても下がらないとは思いますけどねwww

ちなみにこれはtopコマンドの出力の結果となっております。
topコマンドでは
システムで動作しているプロセス, CPU, メモリ, スワップの統計情報について表示させるコマンドなのですが
load averageといってシステムの平均的な負荷も計測することができます。

今回はLoadAvarageについてのお話なので
LoadAvarageに着目して説明します。
まず、一行目に表示されているload average: 2889.63, 638.35, 208.89がLoadAvarage値となっております。
各項目の意味ですが
load average: [1分間], [5分間], [15分間]となっております。
今回の場合ですと
1分間:2889.63
5分間:638.35,
15分間:208.89

これだけの高負荷がかかっているような状況です

 

 

  • LoadAvarageの正常値

じゃぁload avarage値の正常な範囲ってどこなの?

LoadAvarageは処理を待っているプロセスの平均数をもとに計算されております。

プロセスを捌く役割を持っているのがプロセッサー

つまりCPUがたくさんあったり高性能であればあるだけLoadAvarage値は上がりにくいってことです。
あくまで性能の低いものと比較した場合で上がらないわけではないのでそこは勘違いしないでくださいね

さて、今回使用した環境のCPU情報は下記のようになっております。

[root@localhost ~]# cat /proc/cpuinfo 
processor	: 0
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 0
cpu cores	: 6
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

processor	: 1
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 1
cpu cores	: 6
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

processor	: 2
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 2
cpu cores	: 6
apicid		: 2
initial apicid	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

processor	: 3
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 3
cpu cores	: 6
apicid		: 3
initial apicid	: 3
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

processor	: 4
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 4
cpu cores	: 6
apicid		: 4
initial apicid	: 4
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

processor	: 5
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 17
model name	: AMD Ryzen 5 2500U with Radeon Vega Mobile Gfx
stepping	: 0
microcode	: 0x6000626
cpu MHz		: 1996.244
cache size	: 512 KB
physical id	: 0
siblings	: 6
core id		: 5
cpu cores	: 6
apicid		: 5
initial apicid	: 5
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc art rep_good nopl nonstop_tsc extd_apicid pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx rdrand hypervisor lahf_lm cmp_legacy svm cr8_legacy abm sse4a misalignsse 3dnowprefetch retpoline_amd ssbd vmmcall fsgsbase avx2 rdseed clflushopt arat nrip_save flushbyasid decodeassists
bogomips	: 3992.48
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 48 bits physical, 48 bits virtual
power management:

[root@localhost ~]# 

出力の各processorに着目すると
0~5まで出力があります。
つまりこのシステムは0~5の合計6個のプロセッサを持っております。

また、physical id :に着目するとすべて0となっております。
これは物理CPU数を表すものです。
今回はすべて0なのでCPU0の上で6つのプロセッサが動作していると考えてください。

さて、今回のケースでどこまでの負荷なら見過ごしてよいかと考えた場合
プロセッサの数と同じ値ぐらいであればまぁ大丈夫でしょうと考えてよいです
#本番環境であるならば私の経験側ですと1~2 の範囲内であれば大丈夫

また、LoadAvarage値が10を超えたあたりから何かおかしな処理が走っていると確信してよいです。
一時的に発生しているものであれば時間がたてば収束するのですが、
何かしらの原因によって処理がスタックしていたり、
ゾンビプロセスなどが大量に発生していたりする場合は手動での対処が必要となっております。

さて、これらを踏まえたうえでの今回のケースを見ると

load average: 2889.63, 638.35, 208.89

明らかに異常ですよね。。。

 

  • LoadAvarage上昇の原因調査

では、何が原因であるかを考えるときのポイントです。

・TOPコマンドで実行されているプロセスを確認しよう
・プロセスの状態について確認しよう

20956 root 20 0 116372 964 0 D 8.0 0.0 0:00.53 bash
23974 root 20 0 116372 1116 0 D 7.7 0.0 0:00.56 bash
5830 root 20 0 189184 28000 1140 R 6.9 0.6 0:01.82 top
23041 root 20 0 116372 1112 0 D 6.6 0.0 0:00.45  bash
20508 root 20 0 116372 1328 176 R 3.3 0.0 0:00.22 bash

今回の場合ですとやたらとbashが実行されているのがわかりますね。
つまり、bashが怪しい

また各プロセスのステータスについてみていきます。
20956 root 20 0 116372 964 0 D 8.0 0.0 0:00.53 bash

各プロセスの状態の意味は下記のようになっております。

‘D’ = 割り込み不可能なスリープ状態
‘R’ = 実行中
‘S’ = スリープ状態
‘T’ = トレース中/停止された
‘Z’ = ゾンビ

基本的にLoadAvarage値が上昇するのは

このDステータスの際に上昇します。
原因としては

  • 突然大量のプロセスが発生した
  • Disk I/Oが遅いのが原因

改善させるためにはSSDなどのDisk I/Oが高速なものを使用すれば改善されます。

なので問題のプロセスをkillすればとりあえず、LoadAvarage値を下げることができると思いますが
いきなりプロセスをKillするようなことはしないでください
ちゃんとそのプロセスが何をやっていて何に関連しているなど考えて問題ないうえでkillしてください

まぁ今回の場合は操作を受け付けないので電源ぶっちしたんですけどねw

今度の記事はどうやってこのように負荷を増大させたか紹介したいと思います
絶対に本番環境ではやってはいけませんよ(前振り)

 

雑談
ちょっと一息「DynamicConfigService」

こんにちは。 お久しぶりです。 カジマツです。 最近は多忙を極め、全然更新できてませんでした!!!! …

雑談
interop 2019 に行って来ました!!

こんにちは、木尾木公です。 AWS summitの事については既に書いていますが、 同日に、隣の会場 …

雑談
【Amazon】インフラエンジニアの商品紹介

どーも 梶松です。 最近はAWSの資格を取得しようと毎日勉強しています。 そんなことでよくAmazo …