[解決]ログ監視除外設定

ZABBIX3.0.2

アイテムでヒットしたログデータをトリガーにて正規表現を利用しフィルタリングし、
正規表現に合致した文字が含まれる場合にはアクションを起こさないようにしています。

一昨日に実装し昨日、状況を確認したところ、
除外文字列を『除外文字』と仮定した場合、
期待通りに除外されアラートメールは飛ばなくなったのですが、
まれに除外されずアラートメールが飛んできました。
昨日時点、除外されるべきログデータは数十件になりますが、
そのうち3件が除外されずアラートメールが飛んできました。

サーバ負荷等の状況により、このようなことが起こり得る仕様なのでしょうか?

3.2へアップすれば改善されるとか何か情報をお持ちでしたら共有頂けますと幸いです。

コメント表示オプション

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

広瀬です

具体的なトリガー条件式がわかりませんので、仮定としてお話致します。

{Hostname:logrt["{$LOG}",ERROR].regexp(@FILTER)}=1

@FILTER=ABCD

上記で、マクロ指定{$LOG}の中にERROR文字列が含まれ、且つ@FILTER(=ABCD)が
含まれていなければ、イベント発動という条件式になるかと思います。
私が利用しているのは、Ver2.4.8なので全くの比較にはなりませんが、上記で今のところは
ご質問いただいているようなイレギュラー事態の発生はありません。

気になるのは、アクション側で、除外対象となる文字列が含まれていると判断した経緯です。
当該のアクションにマクロは使われていますでしょうか?もし使われているならば、そのマク
ロは{ITEM.VALUE}か、{ITEM.LASTVALUE}のどちらかを利用していないでしょうか?

もちろんバグの可能性もありそうなので、一概には言えませんが気に掛かったのでお答え
いただけると助かります。

ユーザー yukhiro の写真

広瀬さん

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

アイテム定義は以下の通りです。

logrt["/var/log/messages*",@LOGWATCHKEYWORD,,,skip,]
@LOGWATCHKEYWORD=warning|err|crit|alert|emerg
※warning以上のログを捕獲
(例)2016/10/9 hostname warning AA

トリガー定義は以下の通りです。

{LogWatch:logrt["/var/log/messages*",@LOGWATCHKEYWORD,,,skip,].iregexp(@LOGWATCHEXCLUDE)}=0
@LOGWATCHEXCLUDE=AA|BB

広瀬さんとトリガー定義はほぼ同じすが、「=0」と「=1」の違いがあるようです。
「AA|BB」どちらにも該当しない場合は「0」が返されアクションが発動する
「AA|BB」どちらかに該当した場合は「1」が返されアクションは発動しない
との理解でしたが誤った認識(逆が正解)となりますでしょうか?
質問にも書かさせて頂きましたが、上記のトリガー定義で完全ではありませんが不要アラートを抑止できています。

-----------------------------
少々本題から外れてしまいますが、
除外フィルタ語句が増えてくると以下の指定方法では
 @LOGWATCHEXCLUDE=AA|BB|CC|DD|EE|FF・・・
後の第三者がZABBIX正規表現の画面をぱっと見た際、可読性が悪いかなと感じております。
他にもやり方は色々あるのかなとは思いますが、良いTipsなどございましたらアドバイス頂けますと幸いです。

引き続き宜しくお願いいたします。

広瀬です

当方の書き方に問題があり困惑されたかもしれません。お詫びいたします。

=====本来のご質問の件=====
当方が気になっているのは、対象のトリガーに結びつくアクション定義になります。
おそらく通知されたメールから除外した文字列が含まれた状態のものを気づかれたのかと推察します。

先に書いた通り、当該トリガーに紐付く『アクションのメール通知本文』か何かに、{ITEM.VALUE}か
{ITEM.LASTVALUE}をお使いになられていないか、改めてご確認願えませんでしょうか?

 ※先にこちらのご返答をお願いいたします

=====以下、トリガー条件式について======
混同させてしまい、申し訳ありません。私の場合は正規表現フィルターが逆で、『含む』場合
ですので、結果が逆転します。

regexp/iregexpの返り値
1 - found(合致)
0 - otherwise(不一致)

yukhiroさんがご提示のトリガー条件ですと、@LOGWATCHEXCLUDEが『含まれていない』なら
found(=1)を返すって概念です。

2016/10/9 19:05:11 hostname warning AA~BB~CC~
⇒foundを返す(1=0)、なのでトリガー不成立

2016/10/9 20:16:25 hostname warning 11~22~33~
⇒otherwiseを返す(0=0)、なので、トリガー成立

なので、間違いではありませんのでご安心ください。不安に思ってしまい確認いただくのは決して
マイナス要素はありません。私も時々『え~っと』ってなってしまうので、基本の再確認は大事だと
思います<このフォーラムはそういった場ですしね

=====除外フィルタの増加について======

1 » ^lo$ [結果が偽]
2 » ^Software Loopback Interface [結果が偽]
3 » ^(eth[0-7])$ [結果が偽]

上記はLLD利用時のNIC I/FがBondingデバイスの場合のフィルタ条件です。LLDかトリガーに使用する
かはこの際問題ではありませんので、気にしないでください。
上ならば、インターフェース文字列として、1~3のいずれかの条件にあてはまるものを除外となります
ので、可読性は良いかと思います(まぁ、1・3は一緒にしても良いのですが、3は後から足したため)。

@LOGWATCHEXCLUDE=AA|BB|CC|DD|EE|FF・・・

1 » AA|BB|CC [文字列を含まない]
2 » DD|EE|FF [文字列を含まない]

とかでも良いはずです。フィルタしたい文字列を分類したい項目ごとにするなど、その辺は可読性は
各自の判断次第としか言えませんが、助言となれば幸いです。

ユーザー yukhiro の写真

広瀬さん

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

===アクション設定内容確認への回答===============

以下の通りに設定をしております。
再度、詳細は明日出社した際に確認をしたいと思いますが、
確かなところでは以下の定義に除外文字を含むログ内容が記録されておりました。

 /// 1. {ITEM.NAME1} ({HOST.NAME1}:{ITEM.KEY1}): {ITEM.VALUE1} ///

*********************************************
メール件名:
【障害発生】 {TRIGGER.NAME} : {TRIGGER.STATUS} : {ITEM.VALUE}

メール本文:
障害発生ホスト:{HOST.NAME}
障害発生時刻:{DATE}-{TIME}
障害発生箇所:{TRIGGER.NAME}
状態:{TRIGGER.STATUS}
深刻度: {TRIGGER.SEVERITY}
最新値:{ITEM.LASTVALUE}

Item values:

1. {ITEM.NAME1} ({HOST.NAME1}:{ITEM.KEY1}): {ITEM.VALUE1} <===ここに除外文字を含むログが通知されたことを確認
2. {ITEM.NAME2} ({HOST.NAME2}:{ITEM.KEY2}): {ITEM.VALUE2}
3. {ITEM.NAME3} ({HOST.NAME3}:{ITEM.KEY3}): {ITEM.VALUE3}

--------------------

{{HOSTNAME}:{TRIGGER.KEY}.last(#1)}
{{HOSTNAME}:{TRIGGER.KEY}.last(#2)}
{{HOSTNAME}:{TRIGGER.KEY}.last(#3)}
{{HOSTNAME}:{TRIGGER.KEY}.last(#4)}
{{HOSTNAME}:{TRIGGER.KEY}.last(#5)}

Original event ID: {EVENT.ID}
*********************************************

===トリガ定義と除外フィルタTipsへの回答===============

貴重なアドバイスを頂きましてありがとうございます。
改めて勉強になりました。
ご回答いただいた内容をもとに、色々な設定方法を追求していきたいと思います。

引き続き、どうぞ宜しくお願いいたします。

広瀬です

ご回答、ありがとうございます。ITME.VALUEを設定されているとの事ですね。
本家SIAのドキュメントに以下の通りに記載があります。なお、2.x系と3.x系では若干表現が
逆転していますが、基本は同様ととらえてください

Resolved to either:
1) The historical (at-the-time-of-event) value of the Nth item in the trigger expression, if used in the context of trigger status change,
for example, when displaying events or sending notifications.

2) The latest value of the Nth item in the trigger expression, if used without the context of trigger status change, for example,
when displaying a list of triggers in a pop-up selection window. In this case works the same as "{ITEM.LASTVALUE}".

上記のドキュメント内容に示す通り、今回の場合本来的にはイベント・メール通知なので、1番目の挙動となるはずです。
そこは2.x/3.x系でも変わりはありません。が、今回は2番目に示す動きを示している様子です。
・・・となると、{ITEM.VALUE<1-9>}のマクロの仕様に不備がありそうな雰囲気です。

3.0.3、3.0.4には当該マクロに係るバグ修正はありませんが、3.0.5には関連しそうな修正がありますが、
内容見る限りは、違う可能性が大でありご期待に添えるかは定かではありません。
本家のIssueにはITME.VALUE、ITEM.LATSVALUEに係るOPEN中の諸問題は結構ありそうで、
係る問題は根が深そうです<まぁ、中には両マクロの誤解もあるかもしれませんが

現時点では恐らくバグだろうとしか言えませんが、念のため3.0.5にUPできるならしてみてはいかがでしょうか?
お役に立てず申し訳ありません。

ユーザー yukhiro の写真

環境:ZABBIX3.0.4
※すみません、今さらですがバージョンが誤っておりましたので再度、記載させていただきました。

広瀬さん

ご回答ありがとうございます。
内容承知いたしました。

もしご存じでしたらお教えいただきたいのですが、

<質問1>
通知の中ではITME.VALUEとITME.LASTVALUEの両方を使用しておりますが、
通知された内容が一致するときと、一致しないときがあるようです。
これはどのような理由からとなりますでしょうか?

<質問2>
3.0.2から3.0.4へアップした前後で通知メールのItem values:以下が改行されずに1行で表示されるようになりました。
これは3.0.4のバグでしょうか?
#ITEM.VALUE1~3が1行で表示
#.last(#1)~(#5)が1行で表示

以上となります。
どうぞ宜しくお願いいたします。

ユーザー TNK の写真

<質問1>
通知の中ではITME.VALUEとITME.LASTVALUEの両方を使用しておりますが、
通知された内容が一致するときと、一致しないときがあるようです。
これはどのような理由からとなりますでしょうか?

ITEM.VALUEは、トリガーの条件に合致し、イベントが発生した時の
値です。
ITEM.LASTVALUEは、対象のアイテムの最新値です。
トリガーが発生した後、メールを送信する前に新しい値を取得して
いたら、その新しい値がそのマクロと置き換えられます。

<質問2>
3.0.2から3.0.4へアップした前後で通知メールのItem values:以下が改行されずに1行で表示されるようになりました。
これは3.0.4のバグでしょうか?

恐らく、以下のURLでやり取りされている状況と同様の現象が発生
していると思われます。
https://www.zabbix.com/forum/showthread.php?t=54896

しかし、私の環境では発生していません。
上記URLでも解決はしていません。

もしかして、メールのクライアントとしてOutlookを使用されてい
ませんか?
その場合、勝手に改行や空行を削除するなどメールの表示を書き換
えてしまうので、そのロジックでメールの表示を書き換えられてし
まった可能性が考えられます。

バージョンによってメニュー構成は異なるかもしれませんが、

 ファイル -> オプション -> メール -> メッセージ形式

内の、

 テキスト形式メッセージ内の余分な改行を削除する

にチェックが入っていないか確認してみてください。

広瀬です。

<質問1の回答>
{ITEM.VALUE}の翻訳としては以下です(※2.2のドキュメントから引用のため、1/2の順序がVer3.x系では逆転しています)

次のどちらかになります:
1) トリガーの表示に使用される場合、トリガー条件式中のN番目のアイテムの最新値。この場合、{ITEM.LASTVALUE}と同じ機能です。

2) イベントや通知の表示に使用される場合、トリガー条件式中のN番目のアイテムのヒストリカル(at-the-time-of-event)値。
ヒストリ値が既に削除されているか保存されていない場合、UNKNOWN(不明)となります。

上記、2)に示す通り、イベント画面やメール通知時に表示される場合は、実際に検知された際の値がそっくり返されます
いわば検出した時点の値そのものと思ってください

逆に1)は、アイテム収集タイミング⇒トリガー内部処理周期⇒イベント⇒アクション駆動⇒メール通知と、実際のアイテム収集
からメールが通知されるまで、結構時間が開きます。その開いた間に収集されたアイテムの最新値があった場合ですが、
その最新値が代入される事があり、結果的に検出時点と通知時点で異なる挙動をします。

特に1秒間隔で回しているアイテムにはこのような挙動が結構多くなりがちです。{ITEM.LASTVALUE}は元からその仕様です
{ITME.VALUE}、{ITME.LASTVALUE}の違いに関しては、過去トピックにも同一事例はあるので適時検索いただくと
良いかもしれません。

<質問2の回答>
Update時に改行自体が抹消された可能性もありますし、バグの可能性もあります
一端アクション内部の定義の対象部分を消し、保存してから再度本来の形に入れ直してみてください。

※バグかどうかは未だ調べがついてませんので、直ぐに回答は出来ない状況です。すみません。

ユーザー yukhiro の写真

TNKさま
広瀬さま

ご回答ありがとうございました。
{ITME.VALUE}と{ITME.LASTVALUE}の仕様や挙動の違いを理解することができました。ありがとうございます。

なお、通知メールで改行されない件ですが、Outlookを使用しておりますため、
以下の対応を実施することで改行がされましたことをご報告させていただきます。

ファイル -> オプション -> メール -> メッセージ形式
内の、
 テキスト形式メッセージ内の余分な改行を削除する
にチェックが入っていないか確認してみてください。

以上、お二人には色々と教えていただき有難うございました。
ようやく導入事例も弊社で増えてきて実際に触る場面が多くなってきました。
より一層ノウハウを高め、今後は回答者側として貢献していけたらと思います。

本件は以上をもちましてクローズとさせていただきます。
どうもありがとうございました。