障害発生時に大量に出力されるメッセージの監視制御について
◆質問の背景
現在とあるログに対し、特定のキーワードを含むメッセージが出力された場合に検知するようログ監視の設定をしております。
障害が発生した場合に上記特定キーワードを含むメッセージが大量にログに書き出されるのですが、1件1件のメッセージ検知ごとに
障害発報をするのは運用上好ましくない為、一定時間内に同じメッセージが複数件出力される場合は(現状10秒間に5件以上出た場合は)、
1件の発報となるよう、2つのトリガーに依存関係を持たせ、count式を用いて以下の通り設定をしております。(※下記「現状のトリガー設定」を参照願います。)
◆質問内容
下記トリガー設定により(1)、(2)のように実現したいことができているのですが、
(2)の事象後、数分経過後に再度同じメッセージが出力された場合に、(2)で発報されなかった残りのメッセージ件数分の障害発報が後から
されてしまう、といった事象が発生しております。
【実現できている事象】
(1) 10秒間で4件以下のメッセージ出力の場合 ⇒ トリガー①で検知され、出力件数分の障害発報が実施される。
(2) 10秒間で5件以上のメッセージ出力の場合 ⇒ トリガー②で検知され、最後のメッセージに対する障害発報（1件）が実施される。
【問題事象】
下記の時間でエラーが出力された場合、エラー①～⑤については、10秒以内に5件出力されているため、⑤に対する障害発報が1件出力される。
しかし、そのあと暫くして同じエラーメッセージ⑥が出力された場合に、エラー①～④とエラー⑥の計5件分の発報がなされてしまう。
10/19 16:01:20 エラー出力①
10/19 16:01:21 エラー出力②
10/19 16:01:22 エラー出力③
10/19 16:01:23 エラー出力④
10/19 16:01:24 エラー出力⑤
・・・・
10/19 16:05:00 エラー出力⑥
【実現したいこと】
エラー⑥が出力された際、エラー⑥に対する障害発報のみ行われ、エラー①～④に対する障害発報はなされないようにしたいのですが、
どのように実現すればよいでしょうか。もし対策方法等ご存知でしたらご教示頂けますでしょうか。
また、そもそも質問の背景を実現させるための他の手段・設定等の情報がありましたらご教示頂けますでしょうか。
よろしくお願いいたします。
◆現行情報
zabbixバージョン：4.0
現在のトリガー設定：
1つのアイテムに対し、下記2つのトリガーを設定し、さらにトリガー①の依存関係にトリガー②を指定しています。
トリガー① 条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(10)}>0
障害イベント生成モード：複数
正常時のイベント生成モード：すべての障害
トリガー② 条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(10)}>4
障害イベント生成モード：単一
正常時のイベント生成モード：すべての障害
もしご存知でしたらご教示頂けますよう、よろしくお願いいたします。
Yasumi - 投稿数: 372
トリガー②が、エラー⑥が出力されたときに、エラー①～④とエラー⑥を検知してしまう、という理解でよいでしょうか。
トリガー②は「障害イベント生成モード：単一」になっているため、
トリガーのステータスが「復旧」にならない限りは、新しく検知することはないはずです。
つまり、トリガー②が何度も検知するということは、何度もトリガーのステータスが復旧⇔障害に遷移しているということです。
エラー①～④まで検知してしまうのは、なぜかは現時点で分かっていませんが、
設定としてはトリガー②の復旧になる条件をコントロールする必要があると思います。
m_t - 投稿数: 7
Yasumiさん
コメント、大変ありがとうございます。
>トリガー②が、エラー⑥が出力されたときに、エラー①～④とエラー⑥を検知してしまう、という理解でよいでしょうか。
⇒こちら改めて確認し回答させて頂きます。（記憶ではエラー①～④はトリガー①で発報してしまっていたような気がしています。
復旧条件は現状どのトリガーにも設定していないですね。。
ちなみにですが、「復旧しました！」を示すようなメッセージが特に出力されないような事象のケースでは、
復旧条件を設定するのが難しいと感じております。
そのあたり、ご経験上なにかお知恵がありましたらご教示頂けますでしょうか。
宜しくお願いいたします。
Yasumi - 投稿数: 372
復旧条件式の設定は、主にリソース監視で威力を発揮しますね。
障害: {Template:system.cpu.util.avg(#3)}>90
復旧: {Template:system.cpu.util.avg(#3)}<70
このようにすると、90%を行き来してアラートを何度も検知することを防ぐことができます。
ログ監視ではなかなか採用するのが難しいのはご認識の通りです。
今回だとcountを採用しているので、例えば下記のような復旧条件式は考えられるのかなと思います。
{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(10)}<5
※ちょっと気にしているのは、count()内の秒数で、10秒と短い数値なので適切に機能するのかです。
logrt["/xxx/xxx/tmp.log",@error_message,,,skip]は監視間隔1sとかにしているのでしょうか。
また、復旧条件式を使わずに復旧させる手法としてよくあるのが、nodataを使う方法です。
{Template:eventlog[Application,,"Critical",,,,skip].iregexp()}<>0 and
{Template:eventlog:eventlog[Application,,"Critical",,,,skip].nodata(900)}=0
ただ、nodataを使う場合はいろいろと運用上で意識すべきポイントがあります。
m_t - 投稿数: 7
Yasumiさん
有力な情報大変ありがとうございます。
>トリガー②が、エラー⑥が出力されたときに、エラー①～④とエラー⑥を検知してしまう、という理解でよいでしょうか。
⇒こちらの件改めて確認致しましたが、トリガー①にて障害発報されておりました。
少しわかりにくいので、詳細をご説明させて頂きますと、
◆==ログへ出力されるエラー===================
10/19 16:01:20 エラー①
10/19 16:01:21 エラー②
10/19 16:01:22 エラー③
10/19 16:01:23 エラー④
10/19 16:01:24 エラー⑤
・・・・
10/19 16:05:00 エラー⑥
=========================================
上記タイミングでログにエラーが出力された場合、
トリガー①にて「エラー①～④」を検知しますが、依存関係によりトリガー②に切り替わり、「エラー⑤」だけが障害発報されます。
なお、この時点で『障害』ステータスを確認したところ、「エラー①～④」は『障害』ステータスのままとなっておりました。
次に、「エラー⑥」を単独で出力させると、本来であればトリガー①で「エラー⑥」のみを発報させたいところ、
何故か過去に検知した「エラー①～④、⑥」を合わせた計5件が新規エラーとしてトリガー①で発報されてしまいます。
その際、トリガー②の「エラー⑤」については『回復済み』ステータスになっており、
トリガー①の「エラー①～④」については『障害』ステータスのままになっておりました。
トリガー②に切り替わる際、トリガー①が『回復済み』ステータスへ変更されていないことが
原因と推測しているのですが、正直どこから打開したらよいか手詰まっております。。。
m_t - 投稿数: 7
Yasumiさん
アドバイス頂きました復旧条件式についても試してみました。
結論としては、トリガー②に復旧条件式を追加してましたが、状況変わらず同じ結果となりました。
監視間隔については短時間で機能しない可能性もあるということでしたので、
60秒の監視間隔とし、条件式に設定するcountも以下のように60で検証しております。
◆トリガー②
条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}>4
復旧条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}<5
トリガー①のステータスが『回復済み』へ変更されていないことが原因と推測されますので、
トリガー①にも以下の復旧条件式を設定し検証致しました。
結果としては変わらずトリガー①にて「エラー①～④、⑥」が発報されてしましました。
◆トリガー①
条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}>0
復旧条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}>4
トリガー①についても復旧条件式に設定すべきアイディアなどありましたらご教示頂けますでしょうか。
宜しくお願いいたします。
Yasumi - 投稿数: 372
状況についてだいたい把握できてきました。
ちなみにアイテムの監視間隔はどうなっていますでしょうか。
logrt["/xxx/xxx/tmp.log",@error_message,,,skip]
m_t - 投稿数: 7
Yasumiさん
コメントありがとうございます。
アイテムの監視間隔は「60s」に設定しております。
※countのカッコ内の秒数もアイテムの監視間隔「60s」に合わせる形にしています。
何か策がありましたらコメントのほどよろしくお願いいたします。
Yasumi - 投稿数: 372
これはどうでしょうか。
トリガー①
条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}>0 and {アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}<5
障害イベント生成モード：複数
正常イベントの生成：なし
依存関係：なし
※挙動次第ですが、正常イベントの生成と依存関係は「なし」でもいいかもしれません
トリガー②
条件式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}>4
復旧式：{アイテム名:logrt["/xxx/xxx/tmp.log",@error_message,,,skip].count(60)}<5
障害イベント生成モード：単一
m_t - 投稿数: 7
Yasumiさん
コメントありがとうございます。
また、状況のご連絡が遅くなり大変申し訳ありません。
コメント頂いた上記トリガー設定を検証してみたところ、
問い合わせさせてい頂いた当初の事象は解決致しました。
ただ、検証の中で別の課題が浮き彫りになってしまいました。
こちらについてももし知見がございましたらご教示頂けますでしょうか。
◆別の課題
検証の際、下記のようにwatch関数で1秒ごとにエラーを出力させた場合、
❶最初の4秒間で出たエラー4件はトリガー①で4件分発報される
❷5秒目以降のエラーはトリガー②で1件発報される（それ以降ログに出力されたエラーはトリガー①、②共に発報されない）
という想定でしたが、実際は下記計5件が1分ごとに発報され続ける、という挙動を示しております。
count関数は一度そのカウントがリセットされるものでしょうか。
・トリガー①で4件発報
・トリガー②で1件発報
コマンド例)
watch -n 1 "echo 'test error' >> /tmp/test_log"
もしご存知でしたらご教示願います。
宜しくお願いいたします。
m_t - 投稿数: 7
Yasumiさん
コメントありがとうございます。
また、状況のご連絡が遅くなり大変申し訳ありません。
コメント頂いた上記トリガー設定を検証してみたところ、
問い合わせさせてい頂いた当初の事象は解決致しました。
ただ、検証の中で別の課題が浮き彫りになってしまいました。
こちらについてももし知見がございましたらご教示頂けますでしょうか。
◆別の課題
検証の際、下記のようにwatch関数で1秒ごとにエラーを出力させた場合、
❶最初の4秒間で出たエラー4件はトリガー①で4件分発報される
❷5秒目以降のエラーはトリガー②で1件発報される（それ以降ログに出力されたエラーはトリガー①、②共に発報されない）
という想定でしたが、実際は下記計5件が1分ごとに発報され続ける、という挙動を示しております。
count関数は一度そのカウントがリセットされるものでしょうか。
・トリガー①で4件発報
・トリガー②で1件発報
コマンド例)
watch -n 1 "echo 'test error' >> /tmp/test_log"
もしご存知でしたらご教示願います。
宜しくお願いいたします。