ディープラーニングおよびマイニング用に運用しているマシンで定期実行しているClamAVですが、過去に2回ほど高負荷問題へ対処しています。それにも関わらず昨日再度問題が発生したため、また問題へ対処することにします。

環境

  • OS: Debian Stretch 9.3.0
  • 監視サーバー: Zabbix 3.4
  • ウイルス対策: ClamAV
    • スキャンにはclamdを使ったclamdscanを使用

以前行った対処

最初に発生した問題では、ZabbixからCPU温度、負荷、IO負荷などが上昇しているというものでした。これはrecursion limitの設定以上の階層がディレクトリに存在していたためエラー出力が膨大になってIO負荷が上がったのではないかという結論でした。対処としてrecursion limitの設定値を上げて対処しました。

上記の設定後、テスト用のフルスキャンで問題が発生しなかったので、安心していたのですが、再び定期実行で高負荷が発生する問題が発生しました。そこでClamAVのサービス設定ファイル/lib/systemd/system/clamav-daemon.serviceにおいてCPUQuota=50%として、使用リソースに制限を加えました。

今回発生した問題

昨日、Zabbixより下記のようなエラーがスキャン開始時刻の2時を過ぎて届きました。 そして、朝起きてマシンを確認してみるとまだスキャンが終わっていないようです。 流石に時間がかかりすぎておかしいと思われるため、原因を調査します、

Zabbix>
Problem
----------------
Problem started at 02:31:12 on 2018.01.08
Problem name: Too many processes on Zabbix server
Host: Zabbix server
Severity: Warning

Item values: Number of processes: 309

Original problem ID: xxx

CPU負荷

CPU負荷の確認のため、topコマンドの出力から一部を抜粋してみました。

$ top
PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
603 root      20   0 1981128 1.125g  31924 R  52.6  7.2 425:58.75 clamd

...

19887 root      20   0   54528   2688   2244 S   0.0  0.0   0:00.00 cron
19888 root      20   0    4288    752    676 S   0.0  0.0   0:00.00 sh
19889 root      20   0   10648   3020   2796 S   0.0  0.0   0:00.00 clam-full.+
19890 root      20   0   15768   1640   1308 S   0.0  0.0   0:00.00 clamdscan
19938 root      20   0   54528   2688   2244 S   0.0  0.0   0:00.00 cron
19939 root      20   0    4288    760    684 S   0.0  0.0   0:00.00 sh
19940 root      20   0   10648   2996   2768 S   0.0  0.0   0:00.00 clam-full.+
19941 root      20   0   15768   1744   1412 S   0.0  0.0   0:00.00 clamdscan
19987 root      20   0   54528   2688   2244 S   0.0  0.0   0:00.00 cron
19988 root      20   0    4288    724    644 S   0.0  0.0   0:00.00 sh    

前回の設定通り、clamdのCPU負荷は50%程度で安定しています。 そのためか、今回はCPU温度や負荷に関するZabbixからの警告はありませんでした。この点では期待通りに動作しています。

しかし、どうやらcronで走らせている、ClamAVのフルスキャン用のシェルスクリプトが多重起動しているように見えます。以下は一部抜粋したものですが、実際のところシェルスクリプトだけで50プロセスくらい走っていました。明らかにおかしいです。

プロセス多重起動の確認

先のtopコマンドにより、どうやらスキャン用のシェルスクリプトが多重起動しているらしいということが分かりました。ps -efコマンドでプロセスの詳細を確認してみます。

root     19782   584  0 02:00 ?        00:00:00 /usr/sbin/CRON -f
root     19783 19782  0 02:00 ?        00:00:00 /bin/sh -c /root/clam-full.sh
root     19784 19783  0 02:00 ?        00:00:00 /bin/bash /root/clam-full.sh
root     19785 19784  0 02:00 ?        00:00:00 clamdscan --verbose --move=/var/log/clamav/virus /
root     19834   584  0 02:01 ?        00:00:00 /usr/sbin/CRON -f
root     19835 19834  0 02:01 ?        00:00:00 /bin/sh -c /root/clam-full.sh
root     19836 19835  0 02:01 ?        00:00:00 /bin/bash /root/clam-full.sh
root     19837 19836  0 02:01 ?        00:00:00 clamdscan --verbose --move=/var/log/clamav/virus /

...

root     22716   584  0 02:58 ?        00:00:00 /usr/sbin/CRON -f
root     22717 22716  0 02:58 ?        00:00:00 /bin/sh -c /root/clam-full.sh
root     22718 22717  0 02:58 ?        00:00:00 /bin/bash /root/clam-full.sh
root     22719 22718  0 02:58 ?        00:00:00 clamdscan --verbose --move=/var/log/clamav/virus /
root     22764   584  0 02:59 ?        00:00:00 /usr/sbin/CRON -f
root     22765 22764  0 02:59 ?        00:00:00 /bin/sh -c /root/clam-full.sh
root     22766 22765  0 02:59 ?        00:00:00 /bin/bash /root/clam-full.sh
root     22767 22766  0 02:59 ?        00:00:00 clamdscan --verbose --move=/var/log/clamav/virus /

どうも2:00から2:59まで1分ごとに繰り返しシェルスクリプトが実行されている模様です。 どうやら多重起動以前にCronの設定が間違っている可能性が出てきました。

Cron設定の再確認

ClamAVの導入時にCronの設定を行っていました。

その設定内容は次の通りです。意図としては月曜の2時に開始で、毎週実行させるというものでした。

$ sudo crontab -l
* 2 * * 1 /root/clam-full.sh

この設定ですが、改めてマニュアルを見てみると、「分」の指定が*となっているために、設定としては月曜2時の0~59分に毎分実行という内容になっている模様です。 つまり、スキャン用のスクリプトが60回起動していたことになります。

確かに負荷がかかるはずです…。むしろもっと早く気付くべきでした。フルスキャンスクリプトを単発で走らせるよりも圧倒的にcron実行が負荷がかかっていることに疑問を持つべきでした。

Cron再設定

改めてCronの設定を意図したものに書き換えます。 月曜2時00分に実行開始として、今度は分も正しく指定しました。

$ sudo crontab -e
0 2 * * 1 /root/clam-full.sh

今度こそ想定通りに動作してくれるはずです。

まとめ

以下が今回のまとめになります。

  • ClamAVのCronによる定期実行で再び高負荷問題
  • 今度の問題は2つ
    • プロセス数が多すぎることと
    • スキャンが終わらないことが問題
  • 原因はcrontabの設定ミスで、cronが60回実行されていた
  • crontabを書き換え、今度こそ週1回実行されるようにした

参考

以下が参考にしたDebianのcrontabのマニュアルです。