トリガー条件式のnodata関数の動作について(ログ監視)

いつもお世話になっております。
ログ監視におけるnodata関数について質問させていただきます。

以下のような目的と設定で、ログを監視していますが、
イベントで障害が発生している時間のログが確認できない事象が発生しております。

■目的
・errなどの文字列を含むメッセージが出力された場合障害として検知
・同じアラートが連続して出力された場合もひとつの障害として検知
・障害対象のメッセージが出力してから300秒間メッセージがなければ復旧
※Zabbixは30秒ごとにログを監視する設定

■トリガーの設定
・条件式
({localhost:logrt["/var/log/messages"].iregexp(err|crit|alert|emerg)}=1) and ({localhost:logrt["/var/log/messages"].nodata(300)}=0)

・障害イベントを継続して生成する

■質問
・上述の設定の動きとして、最初に障害対象のログが検知してから30秒ごと(300秒間)にZabbixが障害として検知している障害は、
 最初に検知したメッセージを検知しているのでしょうか。

以上、よろしくお願いします。

コメント表示オプション

お好みのコメント表示方法を選び「設定の保存」をクリックすると変更が反映されます。
ユーザー Yasumi の写真

「障害が発生している時間のログが確認できない」というのはアイテムにログが存在していないという意味ですか?
全体的にアイテムとトリガーを混同したような文章で、質問の意味が分からないです。。。

ですが、気になる部分はあります。まず、nodataを使用しているのに「障害イベントを継続して生成する」をチェックしていたら
nodataを使っている意味が全然ないと思います。

次にlogrt["/var/log/messages"]にiregexp(err|crit|alert|emerg)以外の文字列が出力されたら、トリガーは即時復旧するので
これもnodataを使っている意味を薄めていると思います。正規表現でerr|crit|alert|emergを指定してアイテムへの出力を制限すべきかと思います。

ユーザー dondoc の写真

Yashmi-shaさん

ご回答いただきありがとうございます。

不明瞭な質問内容で申し訳ありません。

アイテムのログには、障害として検知するログが1つは出力されているのですが、
30秒おきにイベントで障害として検知しているログが存在してないという意味です。

例:
17:00:00 error ←障害として検知(アイテムにログが存在する)
17:00:30 ←障害として検知(※ログが存在しない)
17:01:00 ←障害として検知(※ログが存在しない)
 ・
 ・
 ・
 ・
17:05:00 ←障害として検知(※ログが存在しない)
17:05:30 ←障害として検知(※ログが存在しない)
17:06:00 ←障害復旧

※17:00:00のログを継続して検知しているという認識がただしければ、
 ログは存在するということになります。

nodataと「障害イベントを継続して生成」の仕様について誤認していました。

「障害イベントを継続して生成」のチェックを外して対応しようと思います。

ユーザー dondoc の写真

Yashmi-shaさん

ご回答いただきありがとうございます。

不明瞭な質問内容で申し訳ありません。

アイテムのログには、障害として検知するログが1つは出力されているのですが、
30秒おきにイベントで障害として検知しているログが存在してないという意味です。

例:
17:00:00 error ←障害として検知(アイテムにログが存在する)
17:00:30 ←障害として検知(※ログが存在しない)
17:01:00 ←障害として検知(※ログが存在しない)
 ・
 ・
 ・
 ・
17:05:00 ←障害として検知(※ログが存在しない)
17:05:30 ←障害として検知(※ログが存在しない)
17:06:00 ←障害復旧

※17:00:00のログを継続して検知しているという認識がただしければ、
 ログは存在するということになります。

nodataと「障害イベントを継続して生成」の仕様について誤認していました。

「障害イベントを継続して生成」のチェックを外して対応しようと思います。

ユーザー dondoc の写真

Yashmi-shaさん

質問させてください。

>nodataを使用しているのに「障害イベントを継続して生成する」をチェックしていたら
>nodataを使っている意味が全然ないと思います。

上記は何故意味がないのかを教えてください。

ユーザー dondoc の写真

質問方法を変えます。
今回確認したい内容は1つエラーログに対して、障害イベントが11個生成された原因についてです。
トリガーの条件式は以下のように設定しています(最初に記載した条件式は誤りです)。

条件式
({localhost:logrt["/var/log/messages",@xxxx].iregexp(@xxxx)}=1) and ({localhost:logrt["/var/log/messages",@xxxx].nodata(300)}=0)

また、「障害イベントを継続して生成する」にはチェックが入っています。
ログ収集アイテムは正規表現で指定した文字列を含むメッセージのみを収集しています。
nodata関数を使用する目的はトリガーステータスを正常に戻すためです。

まず最初にエラー検知文字列を含むログが出力されて1つ目の障害イベントが生成され、
その後30秒毎に同じ障害イベントが10個生成されました。
後の10個のイベントはnodata関数の評価タイミングで生成されたと推測しております。
and前の条件式はhistory syncerがデータをDBに書き込む際に評価され、nodata関数は
DBに書き込まれた後のデータが評価対象だと認識しています。

nodata関数は指定した期間にDBにデータが書き込まれるかどうかを見ている関数ですが、
障害と判定されたデータかどうかも評価してしまうのでしょうか?

ユーザー yk_taiko の写真

◆30秒ごとに判定する理由
nodata などの時間系関数を使用した場合は「毎分0秒と30秒」のタイミングでトリガー判定が走ります。

- https://www.zabbix.com/documentation/3.0/manual/config/triggers
- https://www.zabbix.com/documentation/2.2/jp/manual/config/triggers

◆各トリガー関数の判定内容
「iregexp」はヒストリの最新のデータを使用して正規表現に引っかかるかどうかを判定します。(第二引数無しの場合)
「nodata」は指定した秒数以内にヒストリ上にデータが存在するかを判定します。

◆ログ出力時のトリガー判定の内容
記載されているトリガーでログが1行されると、以下の挙動となります。
記載を簡易にするため、iregexp の方を条件式「α」、nodata の方を条件式「β」とします。
※時間はなんとなく設定したものです。深い意味はありません
~~~~~~~~~~~~~~~~~~~~
[10:00:15] ログ出力
α=合致(最新文字列合致) and β=合致(0秒) → トリガー=障害

[10:00:30]nodataによる再判定
α=合致(最新文字列合致) and β=合致(15秒) → トリガー=障害

[10:01:00]
nodataによる再判定
α=合致(最新文字列合致) and β=合致(45秒) → トリガー=障害

・・・

[10:05:00]
nodataによる再判定
α=合致(最新文字列合致) and β=合致(285秒) → トリガー=障害

[10:05:30]
nodataによる再判定
α=合致(最新文字列合致) and β=不一致(315秒) → トリガー=正常
~~~~~~~~~~~~~~~~~~~~

◆「継続してイベント生成する」とは
【基本的に】Zabbix でイベントが作成されるタイミングは、トリガーのステータスが「正常」から「障害」になる、もしくは「障害」から「正常」になるタイミングです。
上記に加え、「継続してイベント生成する」ようにすると、トリガーのステータスが「障害」の状態で判定が走り、再度「障害」のステータスと判定された場合にもイベントが作成されます。
(イベント生成タイミングは他にもありますが、分かり難くなるので割愛)

★ここで dondoc さんに質問なのですが、
「同じアラートが連続して出力された場合もひとつの障害として検知」とは具体的にどういうことを指していますか?
少なくとも現在の設定では、「ログが出力されたらその行数分イベントが作成される」ようになってますし、30秒ごとにイベントも作成されます。

「同じアラート」について「@xxxx」で表せているのでしたら、
「障害イベントを継続して生成」のチェックを外せば想定の挙動に近いものになるかもしれません。
「@xxxx」のアイテムに「違うアラート」が含まれているのであれば、Zabbixの機能では要件を満たすのは難しいと思います。

ユーザー dondoc の写真

yk_taikoさん

詳しい説明ありがとうございます。

>★ここで dondoc さんに質問なのですが、
>「同じアラートが連続して出力された場合もひとつの障害として検知」とは具体的にどういうことを指していますか?
>少なくとも現在の設定では、「ログが出力されたらその行数分イベントが作成される」ようになってますし、30秒ごとにイベントも作成されます。

すいません、表現が分かりにくかったようです。
「同じアラートが連続して出力された場合にアラートの数だけ障害イベントが生成される」という意味です。
現在の設定で目的は達成されています。

ユーザー dondoc の写真

回答いただいた方々ありがとうございました。
分かりづらい表現があり、申し訳ありませんでした。

nodataの評価タイミングで障害イベントが生成される挙動について
まだ不明な点はありますが、、「障害イベントを継続して生成する」と
nodataを使用することで不要な障害イベントを生成することは分かりました。
条件式からnodataを削除して対応することにします。

ユーザー Yasumi の写真

なるほど。理解しました。

まだ挙動を理解されていないようですが、「障害イベントを継続して生成する」を入れたままnodataを使用すると、
アイテムにXX件ログが出力され、それがトリガーに合致していたら、30秒ごとにXX回アラートが鳴りますよ?
100件ログが検知したら30秒ごとに100件検知します。

なので、「障害イベントを継続して生成する」を入れたままnodataを使用することはnodataを使う意味がないです。
ログがないというのは単なる勘違いです。

ユーザー yk_taiko の写真

Yasumi-sha さん

>「障害イベントを継続して生成する」を入れたままnodataを使用すると、
>アイテムにXX件ログが出力され、それがトリガーに合致していたら、30秒ごとにXX回アラートが鳴りますよ

XX件のログが同一のアイテムに格納されるのであれば、30秒ごとに再生成されるのは 1 件だけになると思います。
アイテムがXX個に分かれているなら話は違いますが。。。

 ログ出力時→ログが出力された分だけトリガーが動作する→XX回障害判定される→XX件イベントが作成される
 その後30秒毎→タイマープロセスによりトリガーが1回動作する→1回障害判定される→1件イベントが作成される

nodata を入れる意味がないかどうかは、考え方(要件?)にもよると思います。

現在の dondoc さんの設定では、"アイテム取得文字列"="トリガー合致文字列"となっています。
nodata 関数を入れないと、トリガーは永遠に障害状態となります。

★「ログが出力されたら全部出力してほしい」 けど「画面に赤いのが残るのが嫌」ということであれば、
30秒ごとの再通知を許容して nodata を使用し、正常の戻すのも一つの方法だと思います。

ユーザー Yasumi の写真

>yk_taikoさん

「障害イベントを継続して生成する」を入れていると、条件に合致した回数だけトリガーは動作します。
ここはnodataを使っていても同じです。それが30秒ごとになるだけで。
トリガーは永遠に障害状態になるのは、「障害イベントを継続して生成する」を入れない状態でnodataを使わない場合です。

なので、「障害イベントを継続して生成する」を入れない状態で
アイテムの条件を的確に絞ってnodataを使うことで、理想の障害⇔復旧の挙動になると思います。

ユーザー karna の写真

いくつか気になった点がありましたので書き込みさせていただきます。

dondocさん
>アイテムのログには、障害として検知するログが1つは出力されているのですが、
>30秒おきにイベントで障害として検知しているログが存在してないという意味です。
>
>例:
>17:00:00 error ←障害として検知(アイテムにログが存在する)
>17:00:30 ←障害として検知(※ログが存在しない)
(略)
>17:06:00 ←障害復旧

条件式にnodataが含まれる場合、指定した時間内にヒストリがあるかどうかを30秒ごとに自動的にチェックします。
この場合、17:00:00に取得したヒストリを検証してますが、それ以降、新規のヒストリがなくても検証し続けます。
17:00:30のイベントは、”最後のヒストリに文字列が含まれている” かつ ”nodataの指定時間内にヒストリがある”
ため、障害としてイベント生成されています。
17:06:00で”最後のヒストリに文字列が含まれている” しかし ”nodataの指定時間内にヒストリがない”
ため、復旧と判断されています。(ちなみに、それ以降も継続して30秒ごとにチェックはされ続けます。)

>nodata関数は指定した期間にDBにデータが書き込まれるかどうかを見ている関数ですが、
>障害と判定されたデータかどうかも評価してしまうのでしょうか?

ヒストリ(データ)はあくまで監視結果であって、”障害と判定されたデータかどうか”という情報は持っていません。
ヒストリをトリガーで判定し、条件式に合致したら障害イベントを生成します。
nodataは対象アイテムの最後のヒストリのタイムスタンプ(zabbixnに取得した時間)を比較するだけです。

yk_taikoさん
>◆30秒ごとに判定する理由
>nodata などの時間系関数を使用した場合は「毎分0秒と30秒」のタイミングでトリガー判定が走ります。

nodata などの判定タイミングは、(最後にヒストリを取得して、トリガーが検証されてから)30秒ごとになるので、
”毎分0秒、30秒” ではありません。
( 仮に、10:00:15に、ヒストリが更新され、その後変化がない場合、
  10:00:15→10:00:45→10:01:15…
  に検証されることになります。)

Yasumi-sha さん
>「障害イベントを継続して生成する」を入れていると、条件に合致した回数だけトリガーは動作します。
>ここはnodataを使っていても同じです。それが30秒ごとになるだけで。

障害イベントを生成するかどうかなので、チェックにかかわらずトリガーによる判定は、ヒストリが更新されたタイミング(& nodataの30秒ごと)で行われます。
条件式に一致した場合、チェックが入っていると、トリガーの状態が”障害”でも ”障害イベントを生成”しますが、
チェックが入っていなければ、”障害イベント”は生成されません(トリガーの状態は障害を維持)

仮に、短時間に100件エラーログが書き込まれ、その後追加がなくなった場合、「障害イベントを継続して生成する」と
最初に100件に対して、都度障害イベントが発生し、その後はnodataのパラメータの範囲で30秒ごとに1件障害イベントが発生します。
(時間内に何件ヒストリがあっても、対象は最後のヒストリのみで、トリガーは30秒に1回しか動かないので、イベントも1件/30s のみです。)

>トリガーは永遠に障害状態になるのは、「障害イベントを継続して生成する」を入れない状態でnodataを使わない場合です。
復旧判定には[~継続して生成~]は関係しませんね。
今回の設定ですと、ヒストリが更新されると必ずiregexp側が正となるので、nodataを使わない場合、トリガーは永遠に障害状態になります。
(3.4なら手動復旧が可能)

最後に、自分だったら、
・同じアラートが連続して出力された場合もひとつの障害として検知  →エラーログを取りこぼさない
・障害対象のメッセージが出力してから300秒間メッセージがなければ復旧
を実現するのであれば、

障害イベントを継続して生成させ、
・nodata関数で復旧判断させる(余分な通知はごめんなさい)。
・余分な通知は出ない代わりに、トリガーは障害のまま。
の二者択一の判断を仰いで、

それとは別に障害・復旧が対になるようなログがあれば、個別にアイテム・トリガーを設定しますかね。
ログ監視用にホストを分けるというのもありでしょうか。

ユーザー Yasumi の写真

>karnaさん

こんばんは。レスを長くしてすみませんが、karnaさんは私が書いたことを反芻しているでOKでしょうか?
karnaさんの文は、私が前述した文と全く同じことを書いていると認識しています。

ちなみに私なら下記のようにトリガーを設定します。
===========================================
■トリガーの設定
・条件式
{localhost:logrt[/var/log/^messages$,@LOG_MES_ALERT,,skip].iregexp()}<>0 and {localhost:logrt[/var/log/^messages$,@LOG_MES_ALERT,,skip].nodata(300)}=0

・正規表現
LOG_MES_ALERT
err,crit,alert,emerg 大文字小文字を区別しない いずれかが含まれる

・障害イベントを継続して生成しない
===========================================

ユーザー karna の写真

>Yasumi-sha さん

>こんばんは。レスを長くしてすみませんが、karnaさんは私が書いたことを反芻しているでOKでしょうか?
>karnaさんの文は、私が前述した文と全く同じことを書いていると認識しています。

なんか、場外で議論してるようであれですが、
nodata関数による検知件数の部分が異なります。

2018/08/07 - 09:50 (火)
yk_taiko さん
のレスの内容が正しいですね。

>まだ挙動を理解されていないようですが、「障害イベントを継続して生成する」を入れたままnodataを使用すると、
>アイテムにXX件ログが出力され、それがトリガーに合致していたら、30秒ごとにXX回アラートが鳴りますよ?
>100件ログが検知したら30秒ごとに100件検知します。

監視のタイミングで、100件エラーログがあったら、100件アラートが上がります。(ここは異論ありません)
その後のnodataの検知については、トリガーごとに1件(1回)なので、アラートも30秒ごとに1件のみです。
nodataの指定時間内のヒストリの件数や、障害イベントの件数、ホスト上のログの件数等は関係ありません。

余談ですが、
dondoc さん のレスで
>「同じアラートが連続して出力された場合にアラートの数だけ障害イベントが生成される」という意味です。
> 現在の設定で目的は達成されています。

とあるので、「障害イベントを継続して生成」は必要と認識しています。

ユーザー Yasumi の写真

>karnaさん

ああ、私も読み違えてましたが、yk_taikoさんの1件というのは「30秒ごと」の発報ですね。合計を言っているのかと勘違いしていました。
私の「XX回アラートが鳴り」のXXは合計を言っています。
100件エラーログがあったら、30秒ごとに1件ずつ、合計100件アラートが上がります。
なので認識齟齬ありません。

気になるのはnodata(300)なんですが、5分間何も値を受信しなければ戻すって動きになると
思いますので、

例:
17:00:00 error ←障害として検知(アイテムにログが存在する)
17:00:30 ←障害として検知(※ログが存在しない)
17:01:00 ←障害として検知(※ログが存在しない)
 ・
 ・
 ・
17:05:00 ←障害として検知(※ログが存在しない)
17:05:30 ←障害として検知(※ログが存在しない)
17:06:00 ←障害復旧

という動きは正しいと思いますよ。というより30秒ってどこから出てきたのかが不明です。
尚、障害を継続のチェックに関してですが、例えば秒間に複数エラー文字列検知した場合、出た数だけ
イベント通知されるので、最後に検知されてから5分後(トリガー内部周期タイミング次第では6分くらい)
に正常と見なされ、イベントが正常に反転するだけです。

 ※nodata関数の最小稼働が30秒である事、トリガー周期タイミングが30秒毎であることは確かですが・・・

・・・と思うのですが、各回答されている方の内容をじっくり読んだ訳では無いので誤解していたら
すみません。
あと、障害継続のチェックとnodata関数の併用は状況次第では別に意味が無い訳ではありません。そこは
検知の仕方次第では有用です。