clamonacc使用時にclamdのCPU使用率が100%になる件

clamav

Raspberry Pi 4にnextcloud及びclamonaccを入れたら、clamdのCPU使用率が100%になってしまいました😅
この問題を自分なりに調べて解決したので紹介します🖥

nextcloud、clamonacc導入についてはそれぞれ以下を参照ください。

nextcloudの反応が顕著に遅くなった

まずnextcloud、その後にclamavのリアルタイムスキャンであるclamonaccを入れました。

ところが、nextcloudの反応速度が目に見えて遅くなってしまいました。

yatch
yatch

Raspberry Pi 4にnextcloud/clamonacc両方動かすのは無理なのかな?
まずはCPU/RAM使用率を確認してみよう。

https://yasufumi-yokoyama.gq/nextcloud/にアクセスしたときのhtopがこれ。

単にトップページを見るだけなのに、やたらとclamdがCPU食ってます。

ちなみに何もしていないときは↓。
まあ当たり前ですが、CPUはほとんど使いません。

ということで、nextcloudを見たときにCPU使用率が爆上がりする問題がありそうです。

原因究明

yatch
yatch

見ているだけでこんなCPU使用率だと、使い物にならないな。
何をしてこんなにCPU食っているんだろう?調べよう。

まず平常時は問題がなくnextcloud上のファイルにアクセスが来たときに使用率爆上がりのきっかけがありそうなので、clamonaccにフォーカスしてみます。

clamonaccをデバッグ出力つきで動かしてみましょう。

pi@raspberrypi:~ $ sudo clamonacc --verbose --foreground --move=/opt/clamav/quarantine

この状態でnextcloudにアクセスしてみます。
すると、コンソール表示に変化がありました。
静止画だとわかりにくいですが、nextcloudにアクセスした瞬間からconfig.phpやshipped.json、他多数のファイルの対するスキャン動作と思われる出力が延々と表示され、いつまで経っても表示更新が止まることはありませんでした。
 ClamInotif: watching ‘/var/www’ (and all sub-directories) から下の行

ちなみにconfig.phpなどをlsで見てみましたが、更新日時は古いまま。
なので、ファイル書込されたわけではなさそうです。

ということで、ファイル読み取りでスキャンが動作しているという仮説を立てます。

ClamFanotif: attempting to feed consumer queue

というデバッグ出力を元にソースコード箇所を中心に調べます。

yatch
yatch

オープンソースのコードを見るのは久しぶりだな!

まずソースコードをダウンロード。

git clone https://github.com/Cisco-Talos/clamav-devel.git

のちに実施するビルドに必要なツールも入れておきます。

sudo apt install autoconf libtool libxml2-dev libssl-dev libcurl4-openssl-dev

先ほどの出力メッセージでコード内をgrepするとありました。fanotif.cに。

grep -r 'attempting to feed consumer queue' .
./clamonacc/fanotif/fanotif.c: logg("ClamFanotif: attempting to feed consumer queue\n");

周辺のコードを見たら気になる点が。

cl_error_t onas_setup_fanotif(struct onas_context **ctx)
{
    (略)
    if (optget((ctx)->clamdopts, "OnAccessPrevention")->enabled && !optget((ctx)->clamdopts, "OnAccessMountPath")->enabled) {
        logg("ClamFanotif: kernel-level blocking feature enabled … preventing malicious files access attempts¥n");
        (ctx)->fan_mask |= FAN_ACCESS_PERM | FAN_OPEN_PERM;
    } else {
        logg("ClamFanotif: kernel-level blocking feature disabled …¥n");
        if (optget((ctx)->clamdopts, "OnAccessPrevention")->enabled && optget((ctx)->clamdopts, "OnAccessMountPath")->enabled) {
            logg("ClamFanotif: feature not available when watching mounts … ¥n");
        }
        (ctx)->fan_mask |= FAN_ACCESS | FAN_OPEN;
    }
    (略)
yatch
yatch

FAN_ACCESS_PERM | FAN_OPEN_PERM ?
FAN_ACCESS | FAN_OPEN ?
なんかアクセスしただけでイベント起きそうだな…

少し脇道に外れますが、
Raspberry Pi OSではCONFIG_FANOTIFY_ACCESS_PERMISSONSが無効になっています。

pi@raspberrypi:~/clamav-devel/clamonacc $ sudo modprobe configs
pi@raspberrypi:~/clamav-devel/clamonacc $ zcat /proc/config.gz | grep FANOTIFY
CONFIG_FANOTIFY=y
# CONFIG_FANOTIFY_ACCESS_PERMISSIONS is not set

このためOnAccessPreventionは使えません。
従って(ctx)->fan_maskはFAN_ACCESS | FAN_OPENになります。

この2つのマスクをman pageで調べると以下のとおりでした。
ファイル書込しなくても、読み取りだけでイベントが起こりそうです。

FAN_ACCESS
 ファイルやディレクトリがアクセスされた (読み出しが行われた) (ただし、「バグ」の節も参照)。
FAN_OPEN
 ファイルやディレクトリがオープンされた。

更にコードを読んでみましたが、設定などで上記マスクを切り替える方法はなさそうです。
そのため、これがclamavの標準動作ということになります。

UbuntuなどのCPUパワーがある程度確保されている機器では問題ないのかもしれませんが、少なくともRaspberry Pi 4ではパフォーマンス上無視できない影響があります。

また、ウィルススキャンなのでファイル読み取り時のスキャンは不要と言えるでしょう。
 私の理解です。間違っていたらゴメンナサイ…

ともかく、これで原因がわかりました。
 ファイル読み取り時にもスキャンが発動している

解決方法検討

安直にソースコードを修正する方向で行きます。
マスクを変更して書込時のみイベント発生させスキャンすればいいわけです。

このようにします。
単純にマスクをFAN_MODIFYにし、書込時のみイベント発生させます。

--- clamonacc/fanotif/fanotif.c.org     2020-12-10 22:13:14.447953394 +0900
+++ clamonacc/fanotif/fanotif.c 2020-12-10 22:14:26.577192538 +0900
@@ -87,7 +87,7 @@
         if (optget((*ctx)->clamdopts, "OnAccessPrevention")->enabled && optget((*ctx)->clamdopts, "OnAccessMountPath")->enabled) {
             logg("*ClamFanotif: feature not available when watching mounts ... \n");
         }
-        (*ctx)->fan_mask |= FAN_ACCESS | FAN_OPEN;
+        (*ctx)->fan_mask |= FAN_MODIFY;
     }

     if ((pt = optget((*ctx)->clamdopts, "OnAccessMountPath"))->enabled) {
2021/08/18更新
FAN_CLOSEとFAN_OPEN_EXEC (FAN_OPEN_EXEC_PERM)も入れる方がより安全と指摘もらいました。
 Link
Renéさんに感謝!



ビルドしてみましょう。
Raspberry Pi 4では全部で10分ほどかかります。

cd clamav-devel
./autogen.sh
./configure
make

動作確認してみましょう。
nextcloudにアクセスしただけではCPU使用率がさほど上がらないことが確認できますね!

sudo ./clamonacc/clamonacc --config-file=/etc/clamav/clamd.conf --move=/opt/clamav/quarantine

導入

修正の有効性が確認できましたので、実際の運用に入れることを考えます。
大きく以下2つの方針があると思います。

  1. ビルドしたclamav全部をmake installで入れて運用する
  2. clamonaccのみビルドしたものを使う

本来は1が良いですが、既存からの変化点を小さくしたかったので、2とします。

この記事で紹介しているclamonacc.shを変更すれば良いですね。

pi@raspberrypi:~ $ sudo nvim /etc/systemd/system/clamonacc.sh

# 以下/etc/systemd/system/clamonacc.shの内容
#!/bin/bash
while [ 0 != $( systemctl status clamav-daemon | grep -q 'Self checking' ; echo $? ) ];
do
        sleep 5;
done ;
# /usr/bin/clamonacc --move=/opt/clamav/quarantine
%path_to_clamonacc% --config-file=/etc/clamav/clamd.conf --move=/opt/clamav/quarantine

また、この状態ですとnextcloudのログが更新されたときもスキャンが動きます。
ログファイルがウィルスに感染する可能性は高くないと思いますので、スキャン対象から外す方がパフォーマンス低下を避けられます。

nextcloud/config/config.phpに以下の通りlogfile設定として書き足せば良いです。

sudo nvim /var/www/html/nextcloud/config/config.php

# 以下config.phpの内容
<?php
$CONFIG = array (
    (略)
   'logfile' => '/var/log/nextcloud.log',
 );

# 所有権をapache2にしておく
sudo touch /var/log/nextloud.log
sudo chown www-data:www-data /var/log/nextloud.log

# apache2再起動
sudo systemctl restart apache2

clamavに問合せてみた

今回の動作、仕様通りなのかバグなのか、いまいち判断ができません。
 単にワタシが無知なだけな可能性も…

bugzillaにチケット作ってみました。
なにか進展ありましたら、報告させていただきます!

終わりに

いかがでしたか。

今回紹介したやり方ですと、従来動作である「読み取り時にもスキャンする」ができなくなってしまうので、設定ファイルにbool設定を追加し、

optget((*ctx)->clamdopts, "ScanModifyOnly")->enabled

みたいにして設定値をclamonacc内で取得し、動作切替できるとよりよいかもです!

Comments

タイトルとURLをコピーしました