Windows ログ監視によるCPU高負荷について

Ver:Zabbix 3.0.10 および 3.0.22
OS:Windows7 32bit

お世話になります。
タイトルの件、ご教授頂きたく宜しくお願い致します。

社内でzabbixによる監視を検討しており、いろいろと試しているのですが
上記エージェント環境のログを監視を試してみたところ、CPU高負荷になります。

具体的にいうと下記監視対象ログからエラー対象の4行目のログ1行を抽出するのに
zabbix_agents.exe が使える分だけCPUを使用して使用率100%が10分程継続します。
尚、抽出は問題なくおこなえております。

DebugLevel=4 にてログを確認したところ、1行目と3行目のログを確認してる際に
下記ログがひたすら出力されていました。

2824:20181015:102929.199 In collect_perfstat()
2824:20181015:102929.217 End of collect_perfstat()
2824:20181015:102930.245 In collect_perfstat()
2824:20181015:102930.261 End of collect_perfstat()

なにか解決策はございますでしょうか。

<正規表現>
SystemOut.log Error for discovery
条件1:dequeueInvoke() invoke error:java.lang.reflect.InvocationTargetException [文字列が含まれない]
条件2:^(.*) (.*) (.*) (.*) (.*) E [結果が真]

<アイテム>
log[C:\Users\xxxxxxx.xxxxxxx\Documents\SystemOut.log,@SystemOut.log Error for discovery,UTF-8,,all]

<監視対象ログ>
[18/10/04 0:40:34:376 JST] 00000001 WsmmConfigFac I ARFM5007I: セル xxxxxx01Cell01 の ARFM 構成は { arfmManageCpu=true arfmQueueMode=cluster ARFM.Mode=Automatic ARFM.MagicNOverride=-1 ARFM.MagicNMode=false aggregationPeriod=5.0 sec ctlCycleMinLength=59.0 sec smoothingWindow=12 maxQueueLen=1000 cpuLimit=100% cpuLimitForCappedVMs=95.0% WorkProfiler.Period=1.0 min WorkProfiler.HalfLife=10.0 min WorkProfiler.AlphaSmoothingHalfLife=10.0 min UseODRs=true WorkProfiler.UseProcessCPU=true WorkProfiler.UseOverhead=false goodnessWeightThreshold=20.0 goodnessWeightFactor=20.0 rhoWeightThreshold=20.0 rhoWeightFactor=8.0 goodnessThreshold=20.0 timeoutFactor=-1.0 timeoutRelaxMinutes=5.0 stuckTension=1.0 initialNominalSrvTime=100 inactivityMinutes=5.0 borrowFactorLimit=1.0 limitBorrowingByPackedPower=false serverStatsWaitTime=2000 nomSrvTimeHalfLife=60000 ratioHalfLife=600000 dlgDspRateHalfLife=600000 msgDspRateHalfLife=300000 initialMsgDlgRatioHalfLife=600000 initialMsgDlgRatio=6.0 msgDlgRatioBadTime=300000 highMemUtilLimit=1.0 profilerSolver=null profilerCorrelationLimit=0.95 profilerCorrelationWithYLimit=0.14 profilerCyclesBetweenSaves=15 memoryOverloadProtectionControlBroadcastPeriodSec=30 memoryOverloadProtectionControlBroadcastShortPeriodSec=15 memoryMarginRatio_fromCell=null maxNonFullGcMemoryReleaseMBOverride=-1 explicitGcPeriodSecOverride=-1 gcReleasesQuicklyOverride=null gcOptimizesThroughputOverride=null memUtilUpHalflife=1000000.0 memUtilDownHalflife=0.0 limitPower=false detectTxcViolations=false detectSvcViolations=true averagingWindowInMS=180000 intervalPerIndividualCountsInMS=10000 minStdDevRatio=0.25 maxZoneFactor=0.99 rampUpFactor=0.95 initialMaxRatePerSec=3.4028235E38 storageServiceWaitTimeInMs=5000 rampUpWithoutFeedbackInMs=180000 moc6AveragingWindowInMS=50000 moc6IntervalPerIndividualCountsInMS=1000 moc6UsePersistentStorage=true usePersistentStorage=false useSlope=true fastRampUp=true closeToMaxFraction=0.5 minSlopePointRate=5.0 minSlopePointRateDiff=5.0 concurrencyDivisor=null workProfilerServerStartupDelayMillis=61440 workProfilerMinimumCPUUtilization=0.003000000026077032 minimumCPURhoMultiplier=0.75 minimumCPURhoWeight=5.0 EnableFilters=true SipCpuOverloadProtection=true HttpAdmCtlForCpuOverloadProtection=true SipAdmCtlForCpuOverloadProtection=true AutoMemoryOverloadProtection=true MemoryMarginRatio_pvt=2.0} です。
[18/10/04 0:40:31:266 JST] 00000001 LocationServi E dequeueInvoke() invoke error:java.lang.reflect.InvocationTargetException
[18/10/04 0:40:34:380 JST] 00000001 WsmmConfigFac I ARFM5007I: セル xxxxxx01Cell01 の ARFM 構成は { arfmManageCpu=true arfmQueueMode=cluster ARFM.Mode=Automatic ARFM.MagicNOverride=-1 ARFM.MagicNMode=false aggregationPeriod=5.0 sec ctlCycleMinLength=59.0 sec smoothingWindow=12 maxQueueLen=1000 cpuLimit=100% cpuLimitForCappedVMs=95.0% WorkProfiler.Period=1.0 min WorkProfiler.HalfLife=10.0 min WorkProfiler.AlphaSmoothingHalfLife=10.0 min UseODRs=true WorkProfiler.UseProcessCPU=true WorkProfiler.UseOverhead=false goodnessWeightThreshold=20.0 goodnessWeightFactor=20.0 rhoWeightThreshold=20.0 rhoWeightFactor=8.0 goodnessThreshold=20.0 timeoutFactor=-1.0 timeoutRelaxMinutes=5.0 stuckTension=1.0 initialNominalSrvTime=100 inactivityMinutes=5.0 borrowFactorLimit=1.0 limitBorrowingByPackedPower=false serverStatsWaitTime=2000 nomSrvTimeHalfLife=60000 ratioHalfLife=600000 dlgDspRateHalfLife=600000 msgDspRateHalfLife=300000 initialMsgDlgRatioHalfLife=600000 initialMsgDlgRatio=6.0 msgDlgRatioBadTime=300000 highMemUtilLimit=1.0 profilerSolver=null profilerCorrelationLimit=0.95 profilerCorrelationWithYLimit=0.14 profilerCyclesBetweenSaves=15 memoryOverloadProtectionControlBroadcastPeriodSec=30 memoryOverloadProtectionControlBroadcastShortPeriodSec=15 memoryMarginRatio_fromCell=null maxNonFullGcMemoryReleaseMBOverride=-1 explicitGcPeriodSecOverride=-1 gcReleasesQuicklyOverride=null gcOptimizesThroughputOverride=null memUtilUpHalflife=1000000.0 memUtilDownHalflife=0.0 limitPower=false detectTxcViolations=false detectSvcViolations=true averagingWindowInMS=180000 intervalPerIndividualCountsInMS=10000 minStdDevRatio=0.25 maxZoneFactor=0.99 rampUpFactor=0.95 initialMaxRatePerSec=3.4028235E38 storageServiceWaitTimeInMs=5000 rampUpWithoutFeedbackInMs=180000 moc6AveragingWindowInMS=50000 moc6IntervalPerIndividualCountsInMS=1000 moc6UsePersistentStorage=true usePersistentStorage=false useSlope=true fastRampUp=true closeToMaxFraction=0.5 minSlopePointRate=5.0 minSlopePointRateDiff=5.0 concurrencyDivisor=null workProfilerServerStartupDelayMillis=61440 workProfilerMinimumCPUUtilization=0.003000000026077032 minimumCPURhoMultiplier=0.75 minimumCPURhoWeight=5.0 EnableFilters=true SipCpuOverloadProtection=true HttpAdmCtlForCpuOverloadProtection=true SipAdmCtlForCpuOverloadProtection=true AutoMemoryOverloadProtection=true MemoryMarginRatio_pvt=2.0} です。
[18/10/04 7:06:42:913 JST] 000000f3 WebContainer E com.ibm.ws.webcontainer.internal.WebContainer handleRequest SRVE0255E: /favicon.ico を処理する Web グループ/仮想ホストが定義されていません。

<抽出結果>
[18/10/04 7:06:42:913 JST] 000000f3 WebContainer E com.ibm.ws.webcontainer.internal.WebContainer handleRequest SRVE0255E: /favicon.ico を処理する Web グループ/仮想ホストが定義されていません。

コメント表示オプション

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

行っている事、問題点は概ね理解はしましたが、以下の点ご回答ねがいます

・CPU使用率が上がっているのは、サーバ側ではなく監視対象(Agent)を入れている端末側でしょうか?

・監視設定のアイテムの監視間隔はどの程度にされていますか?

・監視対象のログは既にどの程度の大きさがありますか?

ご確認の程、お願いします。

コメントありがとうございます。

・CPU使用率が上がっているのは、サーバ側ではなく監視対象(Agent)を入れている端末側でしょうか?
はい、監視対象(Agent)を入れている端末です。

・監視設定のアイテムの監視間隔はどの程度にされていますか?
30s にしております。

・監視対象のログは既にどの程度の大きさがありますか?
質問時に記述した4行込みで12行、15.1KBです。

引き続き、よろしくお願い致します。

ユーザー fripper の写真

正規表現(2)の定義に問題があるのではないでしょうか

「^(.*) (.*) (.*) (.*) (.*) E 」という記述に使われている
「.*」の部分は、「任意の文字が0回以上出現する」なので、長さ0の文字列でも合致してしまうほか
区切り文字として考えられている「 」(半角スペース)も合致するパターンです

その結果として、
【このようなパターンが空白区切りで5回出現したうえで、その次の文字が「E」で始まっている】
という条件として解釈されてしまいます

現状のログは12行、と仰っていますが、行先頭のヘッダ部分(と人間が解釈している部分)だけでなく
行末まで続く数KB(2~3KB)の文字列に対して
 ログ中のいろんな場所に複数回登場している空白文字が、設定された正規表現に書かれた
 「区切り文字(を想定して記載された)空白」に当てはまり得る
と考えて、考えうる様々な解釈・当てはめにおいて、さまざまな区切りパターンを全て試したうえで
最終的な「正規表現との合致」を評価されているのだと思います
 https://www.megasoft.co.jp/mifes/seiki/about.html

指定する正規表現の文字列を
「^\S+ \S+ \S+ \S+ \S+ \S+ E .*」(「E」の後にも半角スペース1個)
にしてみるといかがでしょうか?

¥S(大文字S)だと、「空白以外の任意の文字」という意味合いとなり
*(0回以上の繰り返し)ではなく、+(1回以上の繰り返し)として指定することで
不要な最長マッチ試行を排除できるのではないかと思います
 https://www.megasoft.co.jp/mifes/seiki/meta.html

ユーザー yk_taiko の写真

Windows の場合、"\S" は判定しないかもしれません。

「^[^ ]+ [^ ]+ [^ ]+ [^ ]+ [^ ]+ E .*」
でどうでしょうか。

コメントありがとうございます。

大変勉強になりました。
ご指摘のとおり、不要なマッチ試行が動いていたみたいです。

最終的に
「^[^ ]+ [^ ]+ [^ ]+ [^ ]+ [^ ]+ ( *)E .*」
にてCPU高負荷を発生せず、抽出をおこなうことができました。

アドバイスありがとうございました。