ログ監視で大きなレコードが含まれていた場合の挙動について
いつも参考にさせて頂いております。
長文となり失礼します。
zabbix 3.0.9
CentOS 7.3
MariaDB 10.2.6
監視対象がWindows Server 2012 R2 Standardで特定のログ監視が検知しない事象が発生しました。
特に取得不可にはなってはおらず、以前は意図したとおりに検知できていました。
・アイテム設定
log["C:\hoge\src\log\app.log",@app,SHIFT_JIS]
・正規表現
app=(\sERROR\s|\sCRITICAL\s) [結果が真]
上記の設定で監視していたのですが、ある日 CRITICALのログが出力されていたのに
検知できていませんでした。（ヒストリにも表示されない）
Windowsのzabbix_agentd.log には以下のログが出力されていました。
Logfile contains a large record: "21/09/2017 11:57:04 INFO mongo_upload ～省略～" (showing only the first 64 characters). Only the first 256 kB will be analyzed, the rest will be ignored while Zabbix agent is running.
該当のログを見てみると、313079文字(305.74KB)程度のログが1行で度々出力されるようになっていました。
他のログ監視は同様にregexpで「＠」を使用した設定で問題無く検知できています。
①ERRORかCRITICALでregexpしていますが、エージェント側は一度regexp文字列を含まない行も読み込み、
そこからregexp文字列で抽出し、zabbixサーバへ送るという動作なのでしょうか？
また、アイテムを以下のように設定するとヒストリに表示されました。
log["C:\hoge\src\log\app.log", CRITICAL ,SHIFT_JIS,,skip]
②上記のzabbix_agentd.logに出力されたメッセージがでるとregexpの複数指定や正規表現は上手く動作しなくなるのでしょうか？
※「＠」を使用せず以下のようにしてもヒストリに表示されませんでした。
log["C:\hoge\src\log\app.log",(\sERROR\s|\sCRITICAL\s),SHIFT_JIS,,skip]
※以下のように設定するとヒストリには表示されますが、動作が安定していないように見えます。
log["C:\hoge\src\log\app.log"," ERROR | CRITICAL ",SHIFT_JIS,,skip]
例）
hoge ERROR hoge test 1
hoge CRITICAL hoge test 1
と手動でログに書き込んだが、1行しかヒストリに表示されなかったり、
hoge ERROR hoge test 2
hoge CRITICAL hoge test 2
と手動でログに書き込んだが、
hoge CRITICAL hoge test 1
hoge ERROR hoge test 2
としかヒストリに表示されず「hoge CRITICAL hoge test 2」が表示されなかったり。。
以上となります。宜しくお願い致します。
lilith relic - 投稿数: 15
https://www.zabbix.com/documentation/3.2/manual/config/items/itemtypes/l...
For log file records longer than 256kB, only the first 256kB are matched against the regular expression and the rest of the record is ignored.
マッチするはずの文字列が、レコード中の256kB以降に書かれていたら駄目なんじゃないですかね。
かかし - 投稿数: 52
大きなレコードは全てINFOレベルのもので、検知させたいERROR/CRITICAL文字列は含んでいません。
それとは別の行で出力された数十バイトのERROR/CRITICALを含んだ文字列がヒストリに表示されない（検知できない）のです。
wakaba - 投稿数: 228
広瀬です
「(\sERROR|\sCRITICAL)\s」このパターンで試してみてはいかがでしょうか？
但し、以下のエラーに関しては日時の後のINFOではなく、省略された中にERRORかCRITICALが有ったのでは
無いでしょうか？この場合は先に指摘頂いている通り、256KBの制限に引っ掛かります。
Logfile contains a large record: "21/09/2017 11:57:04 INFO mongo_upload ～省略～"
その場合は残念ながら提示したパターンでも救えません。明示的にINFO含む場合を除外する
必要があります。
かかし - 投稿数: 52
>Logfile contains a large record: "21/09/2017 11:57:04 INFO mongo_upload ～省略～"
この生ログを見てみましたが、確かにERRORかCRITICALは含まれておりません。
その後色々試してみましたが、大きなレコードを含んだログファイルの監視で？、かつ正規表現で[結果が真/偽]を使用した場合、うまく動作していないように見えます。
手動でログファイルに以下のように追記し、正規表現をいくつか試してみました。
26/10/2017 10:35:01 INFO ～
26/10/2017 10:35:02 INFO ～
26/10/2017 10:35:03 INFO ～
26/10/2017 10:35:04 CRITICAL ～
26/10/2017 10:35:05 ERROR ～
26/10/2017 10:35:06 INFO ～
26/10/2017 10:35:07 INFO ～
・正規表現
ERROR / CRITICAL [いずれかの文字列が含まれる] ※前後に半角スペースあり
⇒「＠」を使用してもヒストリに表示される。
最初に書いた「※以下のように設定するとヒストリには表示されますが、動作が安定していないように見えます。」は時間が経てば表示されました。
(\sERROR\s|\sCRITICAL\s) [結果が真] もしくは (\sERROR|\sCRITICAL)\s [結果が真]
⇒ヒストリに表示されない。
(\sERROR\s|\sCRITICAL\s) [結果が偽] もしくは (\sERROR|\sCRITICAL)\s [結果が偽]
⇒全行表示される。（INFOのみヒストリに表示されると思っていました）
バグでしょうか？それとも正規表現の書き方が悪いのでしょうか？
宜しくお願い致します。
wakaba - 投稿数: 228
広瀬です
正規表現については特に間違いという事はありません。どのパターン(ここでは明記しないパターンもあり)でも
3.0系、3.2系でも同様な動作をします。
幾つかのパターンで試験してみました。当方で試した限りでは1行が300KBクラスの場合、256KB以内に
検知対象の文字があった場合は、ヒストリーに格納。それ以降だった場合は検出出来ずって状態でした。
まぁ、見事に制限に正しく挙動してるってことですね。
また、3.0.9以前はグローバル正規表現を使ったlog/logrtではAgent自体のメモリリークのバグがあるので、
INFO系で256KB超えのログ直後にERRORが256KB未満だったとしても、検出出来ない何かしらの問題
があっても不思議では無いかも知れません＜ZBX-12231
とは言え、試験的に試されたパターンで正常に引っかからない場合もあるわけですよね・・・となると、WinOS
で吐かれたログの場合に於いて何かしら問題があるという事も考えられなくはなさそうです
※当方はLinuxでしか試験してないので
少し、Win環境での確認もしてみます＜ご期待はなさらず
かかし - 投稿数: 52
>広瀬様
有難う御座います。期待しております！！
>幾つかのパターンで試験してみました。当方で試した限りでは1行が300KBクラスの場合、256KB以内に
>検知対象の文字があった場合は、ヒストリーに格納。それ以降だった場合は検出出来ずって状態でした。
これについては検出できなくても問題ない（理解できる）のですが、
>とは言え、試験的に試されたパターンで正常に引っかからない場合もあるわけですよね・・・
これが困っています。。
wakaba - 投稿数: 228
広瀬です
少しご報告です。Win環境で適当なログにタスクスケジューラ併用ですが、不定期にログを吐くようにして
ERROR文字列がランダムに出る様にした環境で試験してみました。
結論から申し上げると、グローバル正規表現(要するに@付き)を使用すると、なぜか反応しないという
状況が確かに発生しました。AgentのDebugログを引き上げて見ましたが、@付きの場合は
8284:20171031:193117.179 In process_value() key:'ホスト名:logrt["C:\test.log","@ERR",UTF-8,,skip]' value:'(null)'
と、反応しない。逆にアイテムにダイレクトに検知文字列を使うと、
8284:20171031:193617.247 In process_value() key:'ホスト名:logrt["C:\test.log"," ERROR ",UTF-8,,skip]' value:'Oct 31 18:46:11 kernel ERROR hoge hoge '
きっちり引き出されてました。
尚、先にお話した通り、Linuxではそのような挙動は一切見られていません。この事からすると、正規表現自体が
問題というよりも、WindowsOSでの処置に何らかの問題があると考えるのが自然なのかと判断できます。
※尚、ログのエンコードはSHIFT_JISでもUTF-8でも変化はありませんでした
さすがに、私もこれは「をい・・・」って感じです。引き続きZBX3.2/3.4でも確認出来たら対応してみます
fripper - 投稿数: 495
＞value:'(null)'
＞value:'Oct 31 18:46:11 kernel ERROR hoge hoge '
あたり、ログから取得してきたアイテム値が、正しく正規表現マッチング処理まで引き渡されず、
結果的に長さ0のアイテム値となってしまい、マッチングの結果、合致しない‥として捨てられてしまっている‥
といったように見えますね‥
wakaba - 投稿数: 228
広瀬です
fripperさん、上記の件は少し私の検証ミスだったんで、訂正だけさせてください。
value:'(null)'とでるのは、マッチしない文字列の場合は(null)となるようです。
このDebugログの出方は正しいみたいです。
※ERRORが含まれて居ない行があった場合は全てそうなりました
・・・中々難しいですね（＾＾；
かかし - 投稿数: 52
>広瀬様
再現しちゃいましたか。。
私の環境では以下のような結果でしたが、広瀬様の環境では如何でしょうか。
log["C:\hoge\src\log\app.log",(\sERROR\s|\sCRITICAL\s),SHIFT_JIS,,skip] ⇒ ヒストリ表示されず
log["C:\hoge\src\log\app.log"," ERROR | CRITICAL ",SHIFT_JIS,,skip] ⇒ 複数行マッチする行があった場合、動作不安定
@app= ERROR / CRITICAL [いずれかの文字列が含まれる] ※前後に半角スペースあり
log["C:\hoge\src\log\app.log",@app,SHIFT_JIS,,skip] ⇒ 正常にヒストリに表示
現在のところ
log["C:\hoge\src\log\app.log"," ERROR ",SHIFT_JIS,,skip]
log["C:\hoge\src\log\app.log"," CRITICAL ",SHIFT_JIS,,skip]
と分けて設定しておりますが、今後マッチさせるキーワードが増えるとアイテムの数も多くなり非効率で困っています。
アイテムのみ（トリガー無し）で log["C:\hoge\src\log\app.log",@app,SHIFT_JIS,,skip] も暫定設定しておりますが、
まだマッチする生ログが出力されていない為、この設定でグローバル正規表現が使えるのかまだ確かめられていません。
宜しくお願い致します。
wakaba - 投稿数: 228
広瀬です
時間空いてしまいましたが、答えらしきもの見つけました。
結論、POSIX文字クラスを使えってことでした・・・orz＜なんじゃそりゃ
logrt["C:\test.log","([[:space:]]ERROR[[:space:]])"]
logrt["C:\test.log","@RRE",UTF-8,,skip]
※@RREには「[[:space:]]ERROR[[:space:]]」が入ってます
上記の何れのパターンならば正常に動作します。
grepコマンドで実際に試してみると解りますが、「\sERROR\s」でも「[[:space:]]ERROR[[:space:]]」でも
正しく反応してくれます。
これは私的な解釈に基づきますので、間違っているかもしれませんのであしからず。
Wiki辞書からの拝借ですが、POSIX正規表現にはSRE/BRE/EREの３タイプあり、POSIX正規表現で
スタンダードなのは、BREのようです。文字クラスはこのBREに属します。
で、「\s」これはPOSIXじゃなくてPerl正規表現だそうです・・・orz
数多ある正規表現を正しく理解している人なんざ、一握りだろうな・・・（＾＾；
3.2でしたっけ？PCRE正規表現に切り替わったのは・・・。多分この辺が原因で切り替えたのだと思います。
LinuxOSに於いては、もしかしたら「\s」を解釈できる何かがあるのかな・・・これがWinOSの違いとなると
バグなのか、WinOSが持つ正規表現の特性なのか解りませんが、OS差異と言えそうです。
さて・・・これは3.0系はLTSですから本家に聞けば何かしら答え帰ってきそうな気がしますね・・・
heya - 投稿数: 319
ちょっと細かい部分を補足します。
＞Wiki辞書からの拝借ですが、POSIX正規表現にはSRE/BRE/EREの３タイプあり、POSIX正規表現で
＞スタンダードなのは、BREのようです。文字クラスはこのBREに属します。
Zabbix（3.2まで）は、ERE です。ERE（拡張正規表現）は BRE（基本正規表現）の拡張なので、BRE の機能は ERE でも全部使えます（ただし BRE では (){} に \ をつけますが、ERE ではつけないので、完全な上位互換というわけではありません）。
＞3.2でしたっけ？PCRE正規表現に切り替わったのは・・・。
これは、3.4 からです。
おまけ。
・PCRE は Perl 互換の正規表現ライブラリ（ERE の機能は全部使える）
・PHP の ereg_～() は ERE、preg_～() は PCRE、mb_～() は鬼車（Ruby の正規表現でも使われている・Perl のものとほぼ同等）
・grep は BRE＋α
・grep -E (=egrep) は ERE
かかし - 投稿数: 52
結局Windowsはマニュアルに忠実にPOSIX正規表現でないとダメということですね。
今までLinux系でPerl正規表現で問題無く検知できていた、またテスト条件式でも問題無く見えた為、すっかり騙されてしまいました。
有難う御座いました。