vExpertのブログ（日々の地道な運用改善が大切です）

2020年8月21日（金）17時53分　BIGLOBE Style

BIGLOBE鈴木(研)です。

今回は、VMwareの仮想基盤を運用していて、アラーム対応をすることがありますが、その後同じアラームがなるべく出ないように対応するといった改善活動を行った話を紹介いたします。

■事の発端は休日の運用チームからの電話から

ある日、運用チームから休日に電話連絡を受けました。vCenterのディスク使用率が90%を超えたとのことでした。特に、ディスク使用量が急激に増えている場合は、すぐに使用率100%になってしまう場合があり、とても急ぎで対応が求められるので、すぐにサーバにログインしてdfコマンドを実行してみました。

vCenterのサーバ名:~ # df -h
Filesystem                            Size  Used Avail Use% Mounted on
/dev/sda3                              11G  6.5G  3.7G  64% /
udev                                  7.9G  168K  7.9G   1% /dev
tmpfs                                 7.9G   40K  7.9G   1% /dev/shm
/dev/sda1                             128M   39M   83M  32% /boot
/dev/mapper/core_vg-core               50G  281M   47G   1% /storage/core
/dev/mapper/log_vg-log                9.9G  8.5G  950M  91% /storage/log
/dev/mapper/db_vg-db                  9.9G  465M  8.9G   5% /storage/db
/dev/mapper/dblog_vg-dblog            5.0G  331M  4.4G   7% /storage/dblog
/dev/mapper/seat_vg-seat               25G  2.7G   21G  12% /storage/seat
/dev/mapper/netdump_vg-netdump       1001M   18M  932M   2% /storage/netdump
/dev/mapper/autodeploy_vg-autodeploy  9.9G  151M  9.2G   2% /storage/autodeploy
/dev/mapper/invsvc_vg-invsvc          9.9G  384M  9.0G   5% /storage/invsvc

確かに、/storage/logが91%になってました。何回かdfコマンドを実行してみて、/storage/logの使用量の増え方が急激ではないことを確認できたため、緊急性は下がりました。

■「何が原因か？」調べてみた

どのファイルが肥大化しているのか、duコマンドで調べてみました。

vCenterのサーバ名:~ # cd /storage/log
vCenterのサーバ名:/storage/log # du -sh *
16K     lost+found
4.0K    remote
8.3G    vmware

まずは、vmware配下で9.9GBのパーティションのうち、8.3GB使っていることが分かりました。

/storage/log/vmwareでどのディレクトリ/ファイルが肥大化しているのか、さらにduコマンドで調べてみました。

vCenterのサーバ名:/storage/log # cd vmware
vCenterのサーバ名:/storage/log/vmware # 
vCenterのサーバ名:/storage/log/vmware # du -sm *
6       applmgmt
3346    cloudvm
149     cm
4       dnsmasq.log
1       dnsmasq.log.1.bz2
1       dnsmasq.log.2.bz2
1       dnsmasq.log.3.bz2
1       dnsmasq.log.4.bz2
1       dnsmasq.log.5.bz2
120     eam
57      iiad
40      invsvc
0       journal
1       mbcs
1       netdumper
65      perfcharts
1       rbd
44      rhttpproxy
1       rsyslogd
521     sca
10      syslog
168     vapi
1       vapi-endpoint
1       vctop
1823    vdcs
1       vmafd
514     vmafdd
1       vmdir
78      vmware-sps
1       vpostgres
1060    vpxd
13      vsan-health
13      vsm
215     vsphere-client
1       vws
223     workflow

cloudvmというディレクトリ配下が怪しいことが分かり、更に掘ってみました。

vCenterのサーバ名:/storage/log/vmware # cd cloudvm
vCenterのサーバ名:/storage/log/vmware/cloudvm # du -sm *
1       cloudvm-ram-size-output
1       cloudvm-ram-size-output-20200704.bz2
1       cloudvm-ram-size-output-20200705.bz2
1       cloudvm-ram-size-output-20200706.bz2
1       cloudvm-ram-size-output-20200707.bz2
1       cloudvm-ram-size-output-20200708.bz2
1       cloudvm-ram-size-output-20200709.bz2
1       cloudvm-ram-size-output-20200710.bz2
3308    cloudvm-ram-size.log
1       install-parameter.log
0       service-config.log
37      service-control.log

cloudvm-ram-size.logが1つのファイルで3.3GBも使っていることが分かりました。

このファイルは、テキストファイルでした。

vCenterのサーバ名:/storage/log/vmware/cloudvm # file cloudvm-ram-size.log
cloudvm-ram-size.log: ASCII text

このcloudvm-ram-size.logというファイルが何者かを調べてみようと思い、Google先生に聞いてみることにしました。

すると、すぐに下記KBにたどり着きました。

kb.vmware.com

どうも、cloudvm-ram-size.log のログローテーションをしていない不具合に当たったようです。

■障害対応作業の実施

KBの内容に従い、下記対処を実施しました。

/etc/logrotate.d/cloudvm_ram_size.logを下記内容で作成

/storage/log/vmware/cloudvm/cloudvm-ram-size.log{
missingok
notifempty
compress
size 20k
monthly
create 0660 root cis
}

logrotate -f /etc/logrotate.conf

logroteteコマンドを実行した後、/etc/logrotate.d/cloudvm-ram-size.logファイルの中にcompressというキーワードがあることを思い出しました。

案の定、bzip2コマンドが動いていました。

top - 17:53:11 up 582 days, 18:14,  2 users,  load average: 2.20, 2.53, 2.05
Tasks: 199 total,   2 running, 197 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.7%us,  3.1%sy, 12.4%ni, 80.6%id,  0.1%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:     16081M total,    15915M used,      166M free,      899M buffers
Swap:    26619M total,     1802M used,    24817M free,     9124M cached
PID USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+  COMMAND                                                                                     
4761 root      20   0 13444 6920  460 R     98  0.0   5:33.22 bzip2                                                                                       
22744 root      30  10  834m  86m  12m S     10  0.5   0:10.76 vmware-vws                                                                                  
5704 root      20   0 24588 1044  596 S      2  0.0   3771:01 cgrulesengd                                                                                 
7802 vpostgre  20   0  769m  36m  35m S      2  0.2  21:31.12 postgres                                                                                    
8964 root      20   0 1952m 576m  56m S      2  3.6  22318:48 vpxd                                                                                        
10052 vdcs      20   0 1371m 338m  13m S      2  2.1   5369:51 vmware-vdcs                                                                                 
24490 root      20   0 17136 1352  940 R      2  0.0   0:00.01 top                                                                                         
1 root      20   0 10556  668  636 S      0  0.0   7:34.45 init 
・・・

ここで2つの心配をしました。

CPU高負荷でvCenterの動作不具合が起きないか？
圧縮しているせいで、/storage/logの使用率が100%にならないか？

このvCenterは、休日はほとんど何も処理しない業務のVMしか載せていないし、vSphereAPIでシステム連携とかもないから大丈夫であることはわかってはいたので、とりあえずは一安心することにしました。

結果としては、20分ほどかかって処理は無事完了しました。使用率の下記のとおり57%まで下がりました。この時点で運用チームに連絡し、アラームが解消していることを確認してもらい、対応完了としました。

vCenterのサーバ名:/storage/log/vmware/cloudvm # df -h
Filesystem                            Size  Used Avail Use% Mounted on
/dev/sda3                              11G  6.4G  3.8G  63% /
udev                                  7.9G  168K  7.9G   1% /dev
tmpfs                                 7.9G   40K  7.9G   1% /dev/shm
/dev/sda1                             128M   39M   83M  32% /boot
/dev/mapper/core_vg-core               50G  281M   47G   1% /storage/core
/dev/mapper/log_vg-log                9.9G  5.3G  4.1G  57% /storage/log
/dev/mapper/db_vg-db                  9.9G  465M  8.9G   5% /storage/db
/dev/mapper/dblog_vg-dblog            5.0G  331M  4.4G   7% /storage/dblog
/dev/mapper/seat_vg-seat               25G  2.7G   21G  12% /storage/seat
/dev/mapper/netdump_vg-netdump       1001M   18M  932M   2% /storage/netdump
/dev/mapper/autodeploy_vg-autodeploy  9.9G  151M  9.2G   2% /storage/autodeploy
/dev/mapper/invsvc_vg-invsvc          9.9G  378M  9.0G   4% /storage/invsvc

処理完了後のファイルサイズはこのようになっておりました。

vCenterのサーバ名:/storage/log/vmware/cloudvm # ls -l
total 118516
-rw------- 1 root root     7336 Jul  5 23:30 cloudvm-ram-size-output-20200705.bz2
-rw------- 1 root root     7094 Jul  6 23:30 cloudvm-ram-size-output-20200706.bz2
-rw------- 1 root root     7119 Jul  7 23:30 cloudvm-ram-size-output-20200707.bz2
-rw------- 1 root root     7116 Jul  8 23:30 cloudvm-ram-size-output-20200708.bz2
-rw------- 1 root root     7093 Jul  9 23:30 cloudvm-ram-size-output-20200709.bz2
-rw------- 1 root root     6929 Jul 10 23:30 cloudvm-ram-size-output-20200710.bz2
-rw------- 1 root root     6255 Jul 11 18:03 cloudvm-ram-size-output-20200711.bz2
-rw-rw---- 1 root cis     30996 Jul 11 18:03 cloudvm-ram-size.log
-rw-rw-r-- 1 root cis  82297341 Jul 11 18:03 cloudvm-ram-size.log-20200711.bz2
-rw-r--r-- 1 root root   248396 Jul 11 06:00 install-parameter.log
-rw-r--r-- 1 root root        0 Feb  9  2016 service-config.log
-rw------- 1 root root 38581654 Dec 18  2018 service-control.log

3GB越えのファイルが、80MB程度バイトに圧縮されました。

圧縮対象のファイルがテキストファイルであったので、圧縮率が非常に高かったため、パーティションの空き容量が少ない中で、無事処理が完了したと思います。

もし、compressを付けなかったら、私の障害対応作業で/storage/log の使用率は100%になっていただろうと思います。

■まとめ

何年か運用して、じわじわとcloudvm-ram-size.logのサイズが肥大化していき、やっと/storage/logの使用率がアラーム閾値を超えて気づくという、いわゆる不発弾の発見といえるでしょう。こういったものは、製品検証時では見つからないものです。

今回は、運用チームからのアラームコールを対応し、VMware社のKBにすぐたどり着いて対応策が決まったのはラッキーでした。他のvCenterにも後日横展開で同じ対応を実施して改善を図ることが出来ました。

ちゃんと、こういった運用での出来事を横展開で改善していくという活動は大切であることを、実際やってみて認識を新たにしました。こういう活動の積み重ねがインフラの品質を高めるもので、非常に地道ではありますがおろそかにできないことです。

あと、最近はメンバにマシンを触るのを任せっきりで、私自身はあまり触っていない中で、休日に運用チームからアラームコールをもらったので、ドキドキしながらの障害対応作業ではありました。もう少し触って慣れておかないと、いざという時には役に立たないなぁと思いました。普段ちゃんとやってくれているメンバに感謝です。

※ 本記事で記載されている会社名、製品名は、各社の登録商標または商標です。