Windows イベントログ監視での遅延について
お世話になります。
Windowsサーバのイベントログ監視をzabbixで実装したのですが、監視試験を行ったところ
一部のサーバのみでトリガー検出が遅延する現象が発生しています。
zabbix version:2.2.2
監視対象OS:windows2012
--------------------------------------------
[アイテム書式]
キー:eventlog[system,".*hoge.*",,"Kernel-Power","41"]
更新間隔:60
[トリガー書式]
(({hoge_windows:eventlog[system,".*hoge.*",,"Kernel-Power","41"].regexp(".*",#1)}=1)&({hoge_windows:eventlog[system,".*hoge.*",,"Kernel-Power","41"].nodata(120)}=0))
障害イベントを継続して生成:無効
※アクション実行から120秒後にステータスを反転させるため.nodataで&条件にしています
--------------------------------------------
こちらをテンプレートで実装しeventcreateコマンドで監視試験を行ったところ、特定の
サーバ(本番機)のみトリガー検出が30～60分ほど遅延する現象が発生しました。同じテン
プレートに含まれている他の検証サーバなどでは、コマンドでのテストイベントの作成後
更新間隔で即座に検知されるため、挙動の違いについて原因が分からずにいます。
本番機はイベントログの更新頻度も頻繁で、蓄積されている過去のイベント数も多いのが
気になりますが、何か関連があるでしょうか。
MaxLinesPerSecondの設定値についてはデフォルトのため、これから調整して確認しようと
考えています。何か手がかりとなりそうな情報がありましたら是非ご教示ください。
morimoto121 - 投稿数: 4
お世話になります。
切り分けのためにキーアイテムをシンプルにしてみましたが、やはり遅延が発生します。
--------------------------------------------
[アイテム書式]
eventlog[system]
[トリガー書式]
設定なし
--------------------------------------------
この状態で「最新データ」から該当アイテムのヒストリを参照すると以下のようになります。
タイムスタンプ/ローカル時間/ソース/深刻度/イベントID/値
2014/09/15 20:40:50 2014/09/15 19:00:29 Service Control Manager 情報 7036 WMI Performance Adapter サービスは 実行中 状態に移行しました。
2014/09/15 20:40:50 2014/09/15 19:00:28 Service Control Manager 情報 7036 WMI Performance Adapter サービスは 停止 状態に移行しました。
2014/09/15 20:35:50 2014/09/15 18:55:22 Service Control Manager 情報 7036 WMI Performance Adapter サービスは 実行中 状態に移行しました。
zabbixサーバでのタイムスタンプと、監視対象サーバでのローカル時間でアイテム取得に遅延が発生しています。
上記の場合、実際には19:00~20:40までの間に監視対象サーバでイベントが複数個既に発生していますが
この時点では取得してくれません。遅延時間分のタイムラグの後でようやく取得されます。
遅延の間隔はある程度前後しますが、今のところ収束する傾向は見えません。
本番機でのみ発生している現象のため、zabbix_agentd.confを変更しての切り分けはまだ実施出来ない状況です。
morimoto121 - 投稿数: 4
お世話になります。
zabbix_agentd.confのdebug modeを有効にして調査しました。
zabbixエージェントで認識しているイベントIDの先頭/最後と、監視対象側イベント
ビューアーでの先頭/最後で差異が発生している事が原因で遅延となっているようです。
4904:20140919:105357.061 In process_eventlog6() source: 'system' previous lastlogsize: 93543, FirstID: 30334, LastID: 93544
上記のログが出力された時点で、イベントビューアーを確認すると最終イベントの
RecordIDは"93571"となっており、エージェントで認識しているLastID"93544"と一致
しません。また先頭のRecordIDを確認するとイベントビューアーでは"30362"で、エー
ジェントでは"30334"と認識しているため、この値が異なるために差分が発生している
ように見えます（イベント差分数が遅延になるようです）
"http://www.zabbix.jp/node/1121"を参照すると、先頭ID+イベント出力数を加算して
LastIDを計算しているようなので、先頭がずれると全体がずれてしまうのかと思います。
エージェントの再起動などは行っていますが、遅延する現象は変わらずです。
OS側で"ログの全削除"を行ってもイベント先頭のRecordIDは0に戻らないようなので
対処として効果があるかどうか判断つきかねています。
morimoto121 - 投稿数: 4
本件ですが、OS側でログの全削除→zabbixエージェント再起動を行うことで解決しました。
OS側で何らかの原因があり、イベントログ構成がおかしくなっていたのかと思われます。