ディープラーニング・マイニング用マシンで稼働中に発生した高負荷問題への対処を行っていきます。

前回で高負荷の状況をZabbixの監視結果により確認しました。問題がCPU利用率にあることが分かったので、対処していきます。対象環境はGeforce 1070を設定したDebian 9.3となります。

高負荷の原因

以前、ClamAVのスキャンをcrontabで登録しました。定期実行は月曜日の2時に開始としていましたが、問題が発生したのは12/25(月)の2時頃なので、完全に一致しています。

まずはClamAVから原因を探っていきましょう。

clamavのログの確認

ログファイル

ログファイルの/var/log/clamav/clamav.logを確認します。

Mon Dec 25 01:09:49 2017 -> SelfCheck: Database status OK.
Mon Dec 25 02:02:05 2017 -> WARNING: lstat() failed on: /tmp/clamav-71da1bc1a17569e96fc1da675405e1ba.tmp
Mon Dec 25 02:02:05 2017 -> WARNING: lstat() failed on: /tmp/clamav-3a25671e7051161c08f8f63f81862c67.tmp
Mon Dec 25 02:03:07 2017 -> WARNING: lstat() failed on: /tmp/clamav-6cbb41a0f3c115b46e90d489c822fa71.tmp
...
Mon Dec 25 02:06:04 2017 -> WARNING: Directory recursion limit reached, skipping /home/xxxx/.pyenv/versions/anaconda3-5.0.1/pkgs/rope-0.10.5-py36h1f8c17e_0/lib/python3.6/site-packages/rope/base/oi/type_hinting/providers/__pycache__
Mon Dec 25 02:06:04 2017 -> WARNING: Directory recursion limit reached, skipping /home/xxxx/.pyenv/versions/anaconda3-5.0.1/pkgs/rope-0.10.5-py36h1f8c17e_0/lib/python3.6/site-packages/rope/base/oi/type_hinting/providers/__pycache__
...
Mon Dec 25 02:38:47 2017 -> --- Stopped at Mon Dec 25 02:38:47 2017
Mon Dec 25 02:38:47 2017 -> Socket file removed.
Mon Dec 25 09:29:07 2017 -> +++ Started at Mon Dec 25 09:29:07 2017
Mon Dec 25 09:29:08 2017 -> Received 0 file descriptor(s) from systemd.
Mon Dec 25 09:29:08 2017 -> clamd daemon 0.99.2 (OS: linux-gnu, ARCH: x86_64, CPU: x86_64)
Mon Dec 25 09:29:08 2017 -> Log file size limited to 4294967295 bytes.
Mon Dec 25 09:29:09 2017 -> Reading databases from /var/lib/clamav

特にrecursion limitの警告が大量に出ていることが分かります。 表示されているものは16階層くらいはありそうです。

ログサイズの確認

吐き出されたログファイルが結構な大きさになっています。このIO処理で負荷がかかったのでしょうか。

$ sudo ls -al /var/log/clamav/
合計 2720
drwxr-xr-x  3 clamav clamav    4096 12月 25 00:09 .
drwxr-xr-x 13 root   root      4096 12月 25 09:29 ..
-rw-r-----  1 clamav adm    2205483 12月 25 20:30 clamav.log
-rw-r-----  1 clamav adm     424092 12月 25 00:09 clamav.log.1
-rw-r-----  1 clamav adm      17655 12月 17 00:26 clamav.log.2.gz
-rw-r-----  1 clamav adm        148 12月 19 20:05 clamdscan.log
-rw-r-----  1 clamav adm       8679 12月 25 20:29 freshclam.log
-rw-r-----  1 clamav adm      83702 12月 25 00:09 freshclam.log.1
-rw-r--r--  1 clamav adm       3358 12月 17 00:26 freshclam.log.2.gz
drwxr-xr-x  2 clamav adm       4096 12月 13 00:49 virus

設定の変更

このRecursion limitなどへの対処に、clamdの設定を調整してみます。 /etc/clamav/clamd.confを変更します。

設定項目は次の記事を参考におこないました。

順に関連項目を確認してみます。

  • LogFileMaxSize: 0
    • 問題なさそうです
  • MaxConnectionQueueLength: 15
    • スキャン待ちキューは少なめで問題なさそう
  • MaxThreads 12:
    • ひとまず8に設定
  • MaxDirectoryRecursion 15:
    • 前述の16階層に届いていないので25に設定しておきます
  • MaxScanSize 100M, MaxFileSize 25M:
    • dockerなどの巨大ファイルは問題なさそう

階層数の修正を行ったこの状態で一度フルスキャンしてみて確認してみます。

実行確認

スキャン用スクリプトを走らせてみます。

$ sudo systemctl restart clamav-daemon.service
$ sudo bash /root/clam-full.sh

この状態でCoreTempが55℃付近を行ったり来たりしていて通知が頻発したので、 通知抑えるため一旦通知トリガーを60℃にしておきました。

topコマンドを見ていると、clamdが40~80%程度となり、メモリ使用料は3%程度。 CPU Utilのグラフを見ても、前回ほど100%に張り付いたりはしていないみたいです。 ちなみにccminerのメモリ使用率は1.3%、CPU使用率は1.0%程度で、マイニング自体は CPUとメモリには相当余裕がありそうに見えます。

結局はRecursionの階層のWarningが多すぎてIOに影響を与えていたということなのでしょうか。 この設定を修正したので、今後運用しても大丈夫そうに思えます。

追記(2018/01/01)

再度同様に高負荷の問題が発生したため、別の記事で問題対処しています。