現在位置: ホーム / 製品・サービス / 統合システム監視 MIRACLE ZBX / MIRACLE ZBX - Zabbix テック・ラウンジ / Zabbix 3.2以降の新機能解説(Zabbix 4.0を見据えて) その13

Zabbix 3.2以降の新機能解説(Zabbix 4.0を見据えて) その13

こんにちは、MIRACLE ZBXサポートを担当している花島タケシです。 今回は、logrt[]キーでのcopytruncateタイプローテーションがZabbix4.0でサポートされますので、このことについて解説します。

logrt[]キーでのcopytruncateタイプローテーションサポート

ようやくcopytruncateタイプのログ群がサポートされました。
かねてよりlogrt[]キーにてローテーションされるログファイル群のサポートはされていましたが、ようやくcopytruncateタイプでローテーションされるファイル群もサポートされることになりました。

copytruncateとは?

そもそもcopytruncateタイプのローテーションとはどういうものなのでしょう?

Asianux 6上で、'man logrotate'としてマニュアルを確認します。

引用

copytruncate

Truncate the original log file in place after creating a copy, instead of  moving the old log file  and optionally  creating a new one.  It can be used when some program cannot be told to close its logfile and thus might continue writing (appending) to the  previous log.

file forever.   Note that there  is a very small time slice between copying the file and truncating it, so some logging data might be lost.  When this option is used, the create option will have no effect, as the old log file stays in place.

つまり、「オリジナルのファイルをコピーした後に、オリジナルのファイルを切り詰める。
したがって、ほんの少しだけ欠落することもあるよ。」ということです。

なぜ、こういった実装が必要か?ということも記述されていて、「単に移動しただけだと、移動した先に書き込み続けてしまうタイプのアプリケーションがあるからです。

これは簡単にテストプログラムを書けます。あるファイルに対して、FDを開いてからそのファイルをmvします。そして、元々のファイル名でtouchしてファイルを作成しても、FDを開いたままのアプリケーションは元の(移動した先の)ファイルへ出力します。

以前のZabbixにもこういったバグがありました。

実際に手元のAsianux 6で強制的にローテーションをさせると下記のような状態遷移が発生します。

ローテーション前

-rw-------.  1 root root 72207  2月 22 09:17 2018 libvirtd.log

ローテーション後

-rw-------.  1 root root    0 2月 22 09:34 2018 libvirtd.log
-rw-------   1 root root 72207  2月 22 09:34 2018 libvirtd.log-20180222

 libvirtd.logがlibvirtd.log-20180222へmtimeを伴わないコピーが行われ、libvirtd.logが0バイトに切り詰められています。

従来の実装ではなぜダメだったのか?

一見上記のローテーション前後の結果を見ると、従来の実装のままでも問題がないように思われます。

logrt[]キーでの読み込み対象のファイル群は抽出された後に、mtimeが古い順に、そしてmtimeが同じものがある場合、名前の大きい順に並べられ、古い方から読み込み対象とします。
ここが上記の「問題がないように思われる。」理由です。

しかし、オリジナルファイルORGが、COPIEDにコピーされている最中の状況を想像してみましょう。

COPIEDはORGよりmtimeが大きく、ファイルサイズは小さい状況です。このコピーしている最中にlogrt[]キーでの監視が行われると、COPIEDが新しく生成されたファイルであるため、ORGの残りの部分を読み取った後に(当然残りの部分がなければ読み取りませんが)、COPIEDを先頭から読み込みます。

ということは、いわゆるファイルの読み返しが発生するわけです。

さらに、コピー中にORGに新しくログが出力されると、タイミングによってはORGも先頭から読み込むことになり、ここでも読み返しが発生してしまいます。

対策された実装を見ていこう

今回の解説には4.0.0alpha3を用います。

エージェントがログファイルを読み込むための実装は、src/zabbix_agentd/logfiles.cに記述されています。

ファイル読み込みに関する処理の入り口はprocess_logrt()となります。

これは、logrt関連のキーだけでなく、log関連のキーも同様です。
以前は分かれておりソースも読みやすかったのですが、今は一緒になった分読みづらくなっています。

2952 int process_logrt(
...
2959   int rotation_type)
2960 {
...
2972     if (SUCCEED != (res = make_logfile_list(flags, filename, *mtime, &logfiles, &logfiles_alloc, &logfiles_num,
2973       use_ino, err_msg)))
2974     {
...
2984     }
...
3007     if (0 < *logfiles_num_old && 0 < logfiles_num &&
3008       SUCCEED != update_new_list_from_old(rotation_type, *logfiles_old, *logfiles_num_old, logfiles,
3009 l                                         logfiles_num, *use_ino, &seq, &start_idx, lastlogsize, err_msg))
3010     {
3011       destroy_logfile_list(&logfiles, &logfiles_alloc, &logfiles_num);
3012       goto out;
3013     }
3014
3015     if (ZBX_LOG_ROTATION_LOGCPT == rotation_type && 1 < logfiles_num)
3016       ensure_order_if_mtimes_equal(*logfiles_old, logfiles, logfiles_num, *use_ino, &start_idx);
...
3160     }

l.2972にて、make_logfile_list()をコールし、logfilesにファイルリストを生成します。logrt関連の場合は、前回の処理で最後に読んだファイルのmtime以上のファイル群を、mtimeが古い順に、mtimeが同じものは名前の大きい順に並び替えたリストとなります。

次に、ll.3007-3013の処理において、update_new_list_from_old()を用いて、前回処理時に生成したファイルのリストと直前の処理で生成したファイルのリストを比較します。
結果的には、どこまで読み込んだか?やコピーされたファイルはどれか?といった情報を反映させます。

内部的にcopytruncate形式かそうでないかが分かれた実装がされています。
というのも、上記のようにローテーションの仕組みが異なっており、ケアをする点も異なるからです。

copytruncateの場合は、ファイルサイズやi-node, 内部的なmd5値等を用いて判定をしています。

最終的には、旧ファイルリストと新ファイルリストをつき合わせるための二次元配列の表に対し、一致しているかやコピーされたものか?という印をつけて、新ファイルリスト内の序列を決定します。

l.3016において、mtimeが同じファイルに対しての並び替えをします。
これには上記のコピーされたものか?という印や、ファイル名、前回付けた序列等を元に判断しています。

3076   while (NULL != logfiles && i < logfiles_num)
3077   {
3078     if (0 == logfiles[i].incomplete &&
3079       (logfiles[i].size != logfiles[i].processed_size || 0 == logfiles[i].seq))
3080     {
...
3173   }
3174
3175   if (ZBX_LOG_ROTATION_LOGCPT == rotation_type && 1 < logfiles_num)
3176   {
3177     /* If logrt[] or logrt.count[] item is checked often but rotation by copying is slow it could happen */
3178     /* that the original file is completely processed but the copy with a newer timestamp is still in */
3179     /* progress. The original file goes out of the list of files and the copy is analyzed as new file, */
3180     /* so the matching lines are reported twice. To prevent this we manipulate our stored 'mtime' */
3181     /* and 'lastlogsize' to keep information about copies in the list as long as necessary to prevent */
3182     /* reporting twice. */
3183
3184     delay_update_if_copies(logfiles, logfiles_num, mtime, lastlogsize);
3185   }

ファイルリストの序列が完成するとll.3076-3073のブロックで、可能な限りファイルを読み込みます。

copytruncateの場合は最後にdelay_update_if_copies()をコールして、リスト作成時にファイルがコピー中であった場合の処理を入れています。

コピー対象がある場合は読み込まないようになっており、全て読み込み完了した後に、元ファイルが大きくなっている場合に対するケアです。

終わりに

 copytruncateに対する処理を読んで見ましたが、使えるようにはなっていますが、その判定アルゴリズムはかなり複雑です。

使用できるでしょうが、それが完全に問題なくとはまだ言いきれない感じもします。

実際に、下記のようにマニュアルにも記されているため、気をつけて使用してください。

https://www.zabbix.com/documentation/4.0/manual/config/items/itemtypes/log_items#notes_on_handling_copytruncate_log_file_rotation

The agent tries to handle all these situations reasonably well, but good results cannot be guaranteed in all circumstances. 

関連記事

注意事項

本ドキュメントの内容は、予告なしに変更される場合があります。
本ドキュメントは、限られた評価環境における検証結果をもとに作成しており、全ての環境での動作を保証するものではありません。
本ドキュメントの内容に基づき、導入、設定、運用を行なったことにより損害が生じた場合でも、当社はその損害についての責任を負いません。あくまでお客さまのご判断にてご使用ください。

 

MIRACLE ZBX 製品・サポートサービス 詳しくはこちら

MIRACLE ZBX Virtual Appliance V3.0 評価版のお申し込み

製品・サービスについてのお問い合わせ

お問い合わせフォームMIRACLE ZBX製品やサポートサービスについてのご相談やご質問は、「お問い合わせフォーム」よりお気軽にお問い合わせください。