死活監視+ログ監視
こんにちは。いつもFORUMを拝見させて頂いています。
悩んでいる設定が2点程あります。
1:死活監視
現在サービスサーバの監視にzabbix-1.8.1を投入し、200台程度のサーバの監視を行っています。
深夜にバックアップが動いてダンプやファイル転送を行うのですが、その時に高負荷になり
実際にはサーバがダウンした訳では無いのに死活監視がDownになってしまい、メールが
飛んでしまう事が度々ありました。
過去のフォーラムの記事で死活監視のトリガーを拝見したので、それを参考に以下のトリガーを
設定しています。監視間隔は60秒なので、5回チェックして全部0ならメールを飛ばす、という仕組みに
したつもりです。
｛ping_template:icmpping.count(315,0)}=5&{ping_template:icmpping.last(0)}=0
高負荷状態でメールが飛ぶ事は減ったのですが、先日サーバのリプレースを行った時に監視対象の
サーバをシャットダウンしたら、当然5回応答が無いのでメールが飛んだのですが、何故かその後
リカバリメールが返ってきて状態も正常になってしまいました(概要ではDownになっています)
アクションは「深刻度=致命的な障害 AND 値=障害」で設定しています。
サーバが落ちているのに正常に戻ってしまった理由が分かりません・・・。
2:ログ監視
/var/log/messagesなど複数のログ監視を30秒間隔で行っています。1つのログに複数のトリガーを
設定しているのですが、たまにトリガーに引っ掛かってもアラートが飛ばない時があります。
linux_log_check_template:log[/var/log/messages].nodata(30)}=0)&({linux_log_check_template:log[/var/log/messages].str(ERROR)}=1)
上記のようなトリガーを複数設定しています。messagesであれば他にもWARNINGやFAILED等です。
同じログに複数のトリガーが同時に引っ掛かった時や、一度に大量に同じトリガーが引っ掛かった時に
メールが飛ばない事がある模様です。同じ状況でも飛ぶ時と飛ばない時がある原因がトリガーの性なのか
仕様なのか判別がつかず悩んでいます。
以上2点お気づきの点等有りましたらアドバイス頂ければと思います。
よろしくお願いいたします。
KAZ - 投稿数: 1085
MINTIAさん
実際に同じ条件で検証してみました。
私の方では概要も正常になりました。
動作的にはこれであってるかと。
MINTIAさんのトリガーが正常になるのは「〜count(315,0)}=5&〜」の箇所がポイントです。これは315秒に通信不可「0」が5回じゃないと条件と一致しません。つまり、6回でも7回でもダメです。
下記のようにするとやりたい事ができるかと。
<code>
ping_template:icmpping.count(315,0)}>4&{ping_template:icmpping.last(0)}=0
</code>
飛ばなかった時の詳細が分かると検証できるのですが、これだけではちょっと調べきれないかと…
ログがどの様に出力されているか、アイテムの設定はどうなっているのか教えて頂けますか？
MINTIA - 投稿数: 40
なるほど・・・！
KAZさんに教えて頂いた通りに設定したら、期待した通りの動きになりました。
本当に有難うございました。
2.ログ監視
アイテムの設定は以下の通りです。
タイプ ：zabbixエージェント(アクティブ)
キー ：log[/var/log/messages]
データ型 :ログ
監視間隔 :30
他にも/var/log/secureなど複数のアイテムを設定しています。
ITEM_LASTVALUEが実際に検知した行ではなく、恐らくですがメールが
飛んだ時の最新行を送ってるぽいので、トリガーで引っ掛けた行と
関係ないログが記載されてる事が有りました。
なので、何のワードで引っ掛けたのか書いた複数のトリガーを
1つのアイテムに設定しています。
ERROR in /var/log/messages や WARNING in /var/log/messages などです。
トリガーの内容は最初に投稿した通りで、strの中身だけ変えた物を複数設定しています。
例えば下記のようなログが出力された時は、トリガーは反応したものの
アクションが実行されませんでした。
2010-02-23 21:30:01.782994500 STATUS: program: connected from: 192.168.XXX.YYY
2010-02-23 21:30:01.782994500 STATUS: program: read: cancel
2010-02-23 21:30:01.782994500
2010-02-23 21:30:01.782994500 STATUS: program: command: abort
2010-02-23 21:30:01.782994500 14369 > ERROR: abort: delivering already finished:
2010-02-23 21:30:01.782994500 14369 > [EOF]
他にもWARNINGやFailedなど、複数のトリガーが1回の検知で同時に引っ掛かった時に
たまにアクションが実行されない事が有りました(ちゃんとメールが飛ぶ時も有ります)
確実に検知した行をメールに載せられれば、トリガーを分ける必要もなく
一つのトリガーにまとめられるのですが・・・
追加質問で大変申し訳無いなのですが、最近zabbix-serverが強制終了する事態が
発生し始めました。終了した時のzabbix-serverのログには
14923:20100224:205853.436 ERROR: nested transaction detected. Please report it to Zabbix Team.
zabbix_server: db.c:380: zbx_db_begin: Assertion `0' failed.
もしくは
18370:20100224:071746.100 One child process died (PID:18456). Exiting ...
18370:20100224:071748.140 Syncing history data...
のようなログが出て終了している模様です。
子プロセスが1個死んだらzabbix-severを強制的に終了させてしまっている
ように見受けられますが、負荷が原因と考えるのが妥当でしょうか？
KAZ - 投稿数: 1085
MINTIAさん
その通りです。昨日その処理をソース追って調べてました。
この頃よく聞くのですが、私の使用している環境(1.4.2/1.6.8)では起きていない様に思えます。(見逃しているのでしょうか…)
念の為…
トリガーのイベント生成が"ノーマル"だとイベントのステータスが変更した時にアクションが実行されます。
1.6からの機能ですがトリガーのイベント生成が"ノーマル＋障害イベントを継続して生成"だとステータスが変わらなくてもアクションが実行されます。(トリガーにnodataを指定しなくてもイベントを検知します。)
すいませんが、別スレをたてて頂きたくA(^^;
一概には負荷とは言えません。
できればスレッドを新しくされた方がフォーラムを読む皆さんに分かり易いと思いますので御協力願いたく。
「zbx_db_begin: Assertion `0' failed.」が気になるので調べてみます。
ちなみに、DBはMySQLのInnoDBですか？
MINTIA - 投稿数: 40
なるほど、ソースレベルでそういう処理になってるなら仕方無いですね。
せめて前後1,2行も一緒にメールに載せられれば大分変わるのですが、今後のバージョンアップに期待します〜。
なるほど。1.6以降のログ監視は特別な理由が無い限り"ノーマル＋障害イベントを継続して生成"を
選んだ方が確実なのでしょうか？nodataはステータスを正常に戻すのに使ってたつもりですが
そもそもアクションが実行されないと困るので、そちらも検討してみます。
了解しました。
確かに本投稿のタイトルと全く関係ない話題ですしその方がよさそうですね。
環境等もそちらの投稿に記載しておきます〜。
KAZ - 投稿数: 1085
MINTIAさん
nodataを使う方法は1.6の機能が出るまで何とかできないか？と悩んだ末の方法で…A(^^;
"ノーマル＋障害イベントを継続して生成"はメールが飛ばない事象の切り分けの為には有効かなと…
只、MINTIAさんの書き込みを再度読み直して思ったのですが、トリガーで検知しているのにメールが飛ばないと言うことですので、nodataを使う方法でも"ノーマル＋障害イベントを継続して生成"でも変わらないかもしれません。
メール飛ばなかった時のZabbixサーバのログとかありますでしょうか？
kodai - 投稿数: 1341
こんにちは。
Zabbix 1.6からはnodata()ではなく「ノーマル + 障害イベントを継続して生成」を利用する方が良いです。nodata()は副作用がありますので。
Zabbixのイベント生成 -> アクションの仕組みは発生したイベントを一時的にescalationテーブルに保存して、3秒ごとにactionテーブルに保存し直すようになっています。(エスカレーションの機能のため)
なぜそうなっているのかは分からないのですが、障害イベントがescalationテーブルに保存されてからactionテーブルに移されるまでの間に、同じトリガーの復旧イベントが発生すると、障害イベントが削除されてアクションが送信されません。
アクション設定で「リカバリメッセージ」にチェックをいれておくと、ひとまずこの問題は回避できます。(ただし、復旧メッセージも届くようになってしまいますが)
MINTIA - 投稿数: 40
KAZさん、kodaiさん
なるほど、nodataを使うよりはノーマル＋障害イベントを
使った方がいいのですね。
トリガーで検知しているのにメールが送信されなかった原因はこれっぽいですね。
これはバグなのか、元々そういう仕様にする前提なのか分かりませんが、個人的には
ちょっと違和感を覚えますね。
試しにnodataを消して、ノーマル + 障害イベントを継続して生成を選択してみました。
過去にメールが飛ばない事があった、1秒間に同じエラー行が大量に発生した時の
ログを切り抜いて50行位の一時ファイルにして、それをcatして貼り付けたところ
確かにメールは飛んだのですが、30通くらいアラートメールが飛んできました。
何回かテストしてみましたが、
1.nodata有りの設定:1回の更新間隔で複数トリガー引っ掛かっても飛ばすメール自体は1通。
但し確実に飛ばしてくれないので信頼性に欠ける。
2.ノーマル + 障害イベントを継続して生成:アラートメール自体は飛ぶが、複数トリガーが
引っ掛かった時に、複数通のアラートメールが飛んできてしまう。
同じログの場合は1回の更新で1通飛ばしてくれればいいのですが、ここらへんは
確実性とトレードオフするしかないのでしょうか？
KAZ - 投稿数: 1085
MINTIAさん
私の知っている範囲では上記の２択かと…A(^^;
kodai - 投稿数: 1341
Zabbixでは複数行のログの障害検知を集約するような機能はないので、やるとしてもトリガーの条件式を工夫するしかないでしょうね。
たとえば以下のように設定すれば、現在の行にerrorが含まれていて、過去1時間以内にerror行が1行の場合のみ通知を行うという条件式になります。
({hostname:item[param].str(error)}=1)&{hostname:item[param].count(3600,error)}=1)
トリガーの条件式を工夫するのもいろいろと制約があってあまり複雑なことはできませんが、ご参考ください。
shota - 投稿数: 3
MINTIAさん、KAZさん、Kodaiさん
横から失礼いたします。
Kodaiさんがコメントされたトリガーのイベント発生動作について確認させてください。
escalationテーブルにトリガーAの障害イベント(E1)が保存されていると仮定します。 

escalationテーブルに保存された障害イベント(E1)がactionテーブルへ移動する処理が実行される前にトリガーAで例１のイベントが発生したとします。
例１）

 トリガーAで障害イベント(E2)発生

 トリガーAで復旧イベント発生

 トリガーAで障害イベント(E3)発生

 トリガーAで復旧イベント発生
この時、escalationテーブルに保存された障害イベント(E1)と
例１で発生した障害イベント(E2~E3)はなかったものとしてアクションが実行されないという認識で良いでしょうか。
当方でもMINTIAさん同様、 障害イベント発生時に紐付けられたアクションが発動しない事例が発生していて悩んでおります。
ちなみにトリガーのイベント生成をノーマル＋障害イベントを継続して生成していますが解決しません。
（リカバリメッセージを有効にする対策は運用面でできません。）
上記認識が正しい場合、ログファイルの文字列監視を漏れ無くメッセージ通知するには復旧イベントが発生する可能性がある文字検索にて障害イベントを発生させるのではなく、 
countで期間内に文字列を検出した数で障害イベントを発生させるなど別の手段を選ぶべきなのでしょうか。。。
参考までに当方で障害イベント発生時に紐付けられたアクションが発動しない事例を報告させていただきす。
■事例

144行のログに障害検出する文字列が12行含まれていた時、 
障害イベントは問題なく12件発生するが障害イベントに紐付けられたアクションは3件しか発動しない。
■事例発生時のイベント

時間 名前  ステータス  深刻度  期限 障害対応コメント アクション

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  21m 48s いいえ          -

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  21m 48s いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          OK 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      正常            未分類  0s      いいえ          - 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          OK 

2010.Mar.03 17:32:49    test.log(Error/Warning)      障害            未分類  0s      いいえ          OK
■事例発生時の設定
＜アイテム設定＞

タイプ：ZABBIXエージェント（アクティブ） 

キー：log[/tmp/test.log]

データ型：ログ 

更新間隔（秒）：300 

アプリケーション： Log
＜トリガー設定＞ 

名前： test.log(Error/Warning)

条件式： ({hogehoge:log[/tmp/test.log].str(Error)}=1)|({hogehoge:log[/tmp/test.log].str(Warning)}=1)
イベント生成：  ノーマル＋障害イベントを継続して生成
＜アクション設定＞ 

リカバリメッセージ：切 

計算のタイプ： (A) and (B) 

コンディション：

                        (A)  トリガーの値 = "障害"

                        (B)  アプリケーション = "Log"
kodai - 投稿数: 1341
はい、その認識で合っています。
その方法もあるでしょうね。あとはアイテムの設定で検知したい文字列で絞り込んだ状態にしておく方法があると思います。たとえばerrorという文字列を検知したい場合、アイテムの設定で
log[/tmp/test.log,error]
と設定しておき、トリガーで
{hostname:log[/tmp/test.log,error].str(error)}=1
としておけば、ヒストリにエラーとして検知したい文字列以外は登録されないはずなので、必ず障害通知メールが送信されるはずです。
いろいろと制約はありますが、ログのエラー行ごとにメールを送信するためには「リカバリメッセージを有効にする」か「事前にアイテムで障害メッセージを絞り込んでおく」方法が行ごとに有効ではないかと思います。
ちなみに、1.8系ではどのような動きをするかまだ試していないです。
KAZ - 投稿数: 1085
shotaさん、MINTIAさん、KAZさん、Kodaiさん
なるほど…
私の環境では、普通に動いていた様なので謎だったんですが…A(^^;
おかげさまで、一晩で一万件とかメールが飛んできて泣きが入る時があるんですよ…A(^^;
おかげでメールサーバが何回落ちたか…
下記は盲点でした…
が、エラーが大量に出ているのに全く飛ばなくなるのも…
難しいですね…
<code>
({hostname:item[param].str(error)}=1)&{hostname:item[param].count(3600,error)}=1)
</code>
kodai - 投稿数: 1341
マニュアルを見ていて思いついたので投稿しておきます。
アクションの設定でマクロ機能を利用して、たとえば
<code>{host:log[/var/log/messages].last(0)}
{host:log[/var/log/messages].last(#2)}
{host:log[/var/log/messages].last(#3)}
{host:log[/var/log/messages].last(#4)}
{host:log[/var/log/messages].last(#5)}</code>
と設定すれば、障害通知時の最後のアイテムデータから5つまで遡ってメールに記載できるのではないかと思います(未確認)。
shota - 投稿数: 3
kodaiさん、コメントありがとうございました。
上記設定で数日間運用してみましたが、
すべての障害イベントでアクションが漏れ無く発生すること確認いたしました。
ただKAZさんがコメントされているとおり、ログによっては大量のアラートが送信されることもあるので、どういったトリガーでアラート通知するかは実際の運用で見極めていくしかないですね。。。
これまでアクションが発動せずに悩んでいましたが、発動しない納得できる理由もわかり、解消もできてやっとすっきり致しました。
MINTIA - 投稿数: 40
私もこちらを試したところ、問題無く動作しました。
/var/log/messagesに複数のトリガーを設定しているので
以下のように設定しました。
・アイテム
log[/var/log/messages,failed|Failed|FAILED|warning|Warning|WARNING]
・トリガー
({linux_log_check_template:log[/var/log/messages,failed|Failed|FAILED|warning|Warning|WARNING].iregexp(warning)}=1)&
({linux_log_check_template:log[/var/log/messages,failed|Failed|FAILED|warning|Warning|WARNING].nodata(30)}=0)|
({linux_log_check_template:log[/var/log/messages,failed|Failed|FAILED|warning|Warning|WARNING].iregexp(failed)}=1)&
({linux_log_check_template:log[/var/log/messages,failed|Failed|FAILED|warning|Warning|WARNING].nodata(30)}=0)
見ての通り、アイテムの設定で正規表現が出来てないので
アイテムもトリガーも長くなってしまっています。
1.6のcustomizeguideを見たところログ監視のアイテムのところで
log[file <,regexp >] と書いてあったのですが、,が<>の中にあったり
大文字小文字を区別して欲しくないのでregexpではなくiregexpを
使いたいのですが、アイテムでそれを設定する事は出来ないのでしょうか？
KAZ - 投稿数: 1085
MINTIAさん