「became not supported: Not supported by Zabbix Agent」について

いつもフォーラムを拝見させて頂いておりますが、どうしても解決に至らないため投稿
させて頂きます。

現在以下のような現象が発生しております。

--監視サーバ--
OS:CentOS 6.1(32bit)
Zabbix Server:1.8.10-1

--監視対象サーバ--
OS:Windows 2008 R2 Enterprise Edition SP1(64bit)
Zabbix Agent:1.8.10-1

アイテム:説明…CPU使用率
 タイプ…Zabbixエージェント
 キー…perf_counter[\Processor(_Total)\% Processor Time]
 データ型…数値(浮動小数)
 単位…%
 乗数を使用…チェックなし
 更新間隔(秒)…60
 ヒストリの保存期間(日)…92
 トレンドの保存期間(日)…92
 保存時の計算…なし
 値のマッピングの使用…なし

CPU使用率を上記設定にて採取しているのですが、突然採取できない状態に
なることがあります。そのあと、しばらくすると自然復旧します。

/var/log/zabbix/zabbix_server.logには、

--------------------------------------------------
1810:20120223:181436.953 item [******:perf_counter[\Processor(_Total)\% Processor Time]] became not supported: Not supported by Zabbix Agent

1810:20120223:182037.166 item [******:perf_counter[\Processor(_Total)\% Processor Time]] became supported
--------------------------------------------------

と表示されます。

「became not supported」と出た時、監視サーバから以下のコマンドで確認
すると正常に値を採取できます。

--------------------------------------------------
zabbix_get -s ****** -p 10050 -k "perf_counter[\Processor(_Total)\% Processor Time]"
--------------------------------------------------

現象発生時、監視対象サーバのzabbix_agend.logには何も出力されておりません。

現在、経過観察しているのですが、同様の事象に合われた方がいらっしゃったら
情報頂けると助かります。

以上よろしくお願いいたします。

コメント表示オプション

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

同じような現象を以前どこかで見たことがある気がします。

  1. 問題が出ているホストで、パフォーマンスカウンタのアイテムはどの程度設定されているでしょうか?
  2. また、その取得間隔はどの程度でしょうか?
  3. 可能であれば、エージェントをデバッグモードにして、ログにエラーなどがないか確認いただけると助かります。
ユーザー fuchi の写真

返信ありがとうございます。
確認した結果は以下のとおりです。

1.問題が出ているホストで、パフォーマンスカウンタのアイテムはどの程度設定されているでしょうか?
 ⇒パフォーマンスカウンタのアイテムは「1つ」です。

2.また、その取得間隔はどの程度でしょうか?
 ⇒取得間隔は「60秒」です。

3.可能であれば、エージェントをデバッグモードにして、ログにエラーなどがないか確認いただけると助かります。
 ⇒こちら調整が必要ですので,少し時間がかかりそうです。
  確認でき次第,アップさせていただきます。

ささいなことでも結構ですので,他に情報をお持ちの方がいらっしゃったらコメント頂けると助かります。

-追加情報-
・監視対象ホストはHyper-V上のゲストOS
・問題が出るホストは不定期で入れ替わる
・監視対象ホストは数台あり,問題が出るホストはその中の数台
・問題が出るホストと問題が出ないホストの違いを現在精査中

ユーザー fuchi の写真

「3.可能であれば、エージェントをデバッグモードにして、ログにエラーなどがないか確認いただけると助かります。」について
情報を採取しました。「分母の値が負のカウンターが検出されました。」と表示されております。

■異常時
 =zabbix_server.log=
1810:20120306:130928.544 item [******:perf_counter[Processor(_Total)% Processor Time]] became not supported: Not supported by Zabbix Agent
=zabbix_agentd.log=
5448:20120306:130923.745 Processing request.
5448:20120306:130923.745 Requested [perf_counter[Processor(_Total)% Processor Time]]
5448:20120306:130923.761 In PERF_COUNTER()
5448:20120306:130923.761 PERF_COUNTER(): PerfCounter 'Processor(_Total)% Processor Time' successfully added
6624:20120306:130924.448 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:130924.448 End of send_buffer():SUCCEED
6624:20120306:130924.448 Sleeping for 1 second(s)
6004:20120306:130924.448 In collect_perfstat()
5448:20120306:130924.761 PERF_COUNTER(): cannot calculate counter value 'Processor(_Total)% Processor Time': [0x800007D6] 分母の値が負のカウンターが検出されました。
5448:20120306:130924.761 End of PERF_COUNTER()
5448:20120306:130924.761 Sending back [ZBX_NOTSUPPORTED]
……
6624:20120306:131027.493 Sleeping for 1 second(s)
6004:20120306:131028.461 In collect_perfstat()
6624:20120306:131028.493 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:131028.493 End of send_buffer():SUCCEED
6624:20120306:131028.493 Sleeping for 1 second(s)
7540:20120306:131028.805 Processing request.
7540:20120306:131028.805 Requested [vm.memory.size[free]]
7540:20120306:131028.805 Sending back [5966434304]
6612:20120306:131028.821 Processing request.
6612:20120306:131028.821 Requested [vfs.fs.size[d:,total]]
6612:20120306:131028.821 Sending back [53683941376]
6004:20120306:131029.462 In collect_perfstat()

■復旧時
=zabbix_server.log=
1808:20120306:131028.577 item [******:perf_counter[Processor(_Total)% Processor Time]] became supported
=zabbix_agentd.log=
5448:20120306:131023.804 Processing request.
5448:20120306:131023.804 Requested [perf_counter[Processor(_Total)% Processor Time]]
5448:20120306:131023.804 In PERF_COUNTER()
5448:20120306:131023.820 PERF_COUNTER(): PerfCounter 'Processor(_Total)% Processor Time' successfully added
6004:20120306:131024.461 In collect_perfstat()
6624:20120306:131024.492 In send_buffer() host:'***.***.****.***' port:10051 values:0/100
6624:20120306:131024.492 End of send_buffer():SUCCEED
6624:20120306:131024.492 Sleeping for 1 second(s)
5448:20120306:131024.820 End of PERF_COUNTER()
6612:20120306:131024.820 Processing request.
5448:20120306:131024.820 Sending back [0.019196]
 ……
 6624:20120306:131027.493 Sleeping for 1 second(s)
6004:20120306:131028.461 In collect_perfstat()
6624:20120306:131028.493 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:131028.493 End of send_buffer():SUCCEED
6624:20120306:131028.493 Sleeping for 1 second(s)
7540:20120306:131028.805 Processing request.
7540:20120306:131028.805 Requested [vm.memory.size[free]]
7540:20120306:131028.805 Sending back [5966434304]
6612:20120306:131028.821 Processing request.
6612:20120306:131028.821 Requested [vfs.fs.size[d:,total]]
6612:20120306:131028.821 Sending back [53683941376]
6004:20120306:131029.462 In collect_perfstat()
 ……
6624:20120306:131044.511 Sleeping for 1 second(s)
6004:20120306:131045.480 In collect_perfstat()
6004:20120306:131045.480 collect_perfstat(): PerfCounter 'Processor(1)% Processor Time' successfully added
6004:20120306:131045.480 collect_perfstat(): PerfCounter 'Processor(_Total)% Processor Time' successfully added
6624:20120306:131045.512 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:131045.512 End of send_buffer():SUCCEED
6624:20120306:131045.512 Sleeping for 1 second(s)
6004:20120306:131046.481 In collect_perfstat()
 ……

■正常時
=zabbix_agentd.log=
5448:20120306:131123.834 Processing request.
5448:20120306:131123.834 Requested [perf_counter[Processor(_Total)% Processor Time]]
5448:20120306:131123.834 In PERF_COUNTER()
5448:20120306:131123.834 PERF_COUNTER(): PerfCounter 'Processor(_Total)% Processor Time' successfully added
6004:20120306:131124.521 In collect_perfstat()
6624:20120306:131124.537 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:131124.537 End of send_buffer():SUCCEED
6624:20120306:131124.537 Sleeping for 1 second(s)
5448:20120306:131124.849 End of PERF_COUNTER()
5448:20120306:131124.849 Sending back [0.023035]
 ……
6612:20120306:131223.880 Processing request.
6612:20120306:131223.880 Requested [perf_counter[Processor(_Total)% Processor Time]]
6612:20120306:131223.880 In PERF_COUNTER()
6612:20120306:131223.880 PERF_COUNTER(): PerfCounter 'Processor(_Total)% Processor Time' successfully added
6624:20120306:131224.583 In send_buffer() host:'***.***.***.***' port:10051 values:0/100
6624:20120306:131224.583 End of send_buffer():SUCCEED
6624:20120306:131224.583 Sleeping for 1 second(s)
6004:20120306:131224.583 In collect_perfstat()
6612:20120306:131224.880 End of PERF_COUNTER()
6612:20120306:131224.880 Sending back [1.585804]

ユーザー kodai の写真

分母がマイナスということは、時刻情報が問題の可能性があると思います。

監視している対象のWindowsマシンの時刻のずれが大きいということはないでしょうか?
また、NTPなどを利用して時刻を補正されるときに、少しずつ修正するのではなく、一気に時刻を変更されたりしていないでしょうか?

ユーザー fuchi の写真

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

監視している対象のWindowsマシンの時刻のずれが大きいということはないでしょうか?
⇒確認してみましたが、監視サーバと監視対象サーバ間で時刻のずれはほとんどありませんでした。(1秒以内)

また、NTPなどを利用して時刻を補正されるときに、少しずつ修正するのではなく、一気に時刻を変更されたりしていないでしょうか?
⇒時刻の同期は、Hyper-Vの統合サービスの「時刻の同期」を使用しております。
 microsoft社のtechnetによれば5秒以上遅れると補正を行う仕様です。

-追加情報-
監視している対象でパフォーマンスカウンタで[Processor(_Total)% Processor Time]を1秒間隔で
ファイルに採取するとまれに値が取れない箇所がありました。(値がブランクとなる。)

ユーザー kodai の写真

MSのサイトに関連しそうな情報がありました。これだけでは何が原因か分からないのですが...
http://support.microsoft.com/kb/324808/ja

ユーザー fuchi の写真

kodai様、いつもコメントありがとうございます。

サイトを拝見しましたが、これだけですと確かに原因がわかないですね…

いろいろありがとうございます。

回避策として、アイテム(system.cpu.util[,system,])を使用してみましたが、
アイテムを有効にすると頻繁に「取得不可」となってしまいますので断念しました。
ちなみに、上記アイテムは物理マシンでは問題がでませんでした。

現時点では、

・Hyper-V上の仮想マシンでは、パフォーマンスカウンタでのアイテム取得が不安定となる場合がある。

という結論に至っております。

切り分け方法案、Hyper-V上の仮想マシンでパフォーマンスカウンタでのアイテム取得事例などあれば
教えて頂けると幸いです。
ちなみに、過去の投稿でHyper-V上の仮想マシンをZabbixで監視できるという情報は見つけております。
(公式、非公式かは不明ですが)

ユーザー kodai の写真

これまでHyper-V上のホストの監視を行ったことがないので、すぐには原因が思いつかないですね...

エラーメッセージはWindows側のものに見えるのですが、問題がZabbixのパフォーマンスカウンタの値の取得方法にあるのか、Windows側にあるのか、再現できる環境がないと分からなさそうです。

Zabbixエージェント自体は特殊なことはしていないので、基本的にはHyper-V上のWindowsでも問題なく監視できるはずです。

回避策として、アイテム(system.cpu.util[,system,])を使用してみましたが、
アイテムを有効にすると頻繁に「取得不可」となってしまいますので断念しました。
ちなみに、上記アイテムは物理マシンでは問題がでませんでした。

perf_counterを利用すると、Zabbixのアイテムの更新間隔でデータを取得するのですが、system.cpu.utilを利用するとZabbixエージェント内部では1秒ごとにデータを取得して平均値を算出します。system.cpu.utilの方が頻繁にデータ取得を行う分、エラーになる確率も高くなるのだと思います。

ユーザー fuchi の写真

ご返信ありがとうございます。

=========================================================================
perf_counterを利用すると、Zabbixのアイテムの更新間隔でデータを取得するのですが、system.cpu.utilを利用するとZabbixエージェント内部では1秒ごとにデータを取得して平均値を算出します。system.cpu.utilの方が頻繁にデータ取得を行う分、エラーになる確率も高くなるのだと思います。
=========================================================================
⇒ですが、おっしゃる通りですね。承知いたしました。