ログの監視について

お世話になります。

ZABBIX1.6.2でログ監視をするため、アイテム、トリガーを作成したのですがうまくいきません。

ZABBIXサーバ、エージェントは同一のLinuxサーバにインストールし、性能、資源情報は問題なく監視できております。

どこの箇所に原因がありますでしょうか。ご教授いただけたらと思います。

現在の状況は下記の通りです。
[アイテム]
タイプ: ZABBIXエージェント(アクティブ)
キー: log[/var/log/messages]
データ型: ログ
更新間隔(秒): 30
ログ時間の形式: 空白
アプリケーション: Log files

[トリガー]
{ホスト名:log[/var/log/messages].str(error)}=1

・/var/log/messagesのパーミッションは664
・zabbix_agentd.confのDisableActive=1はコメントアウトされています。

[設定]-[アイテム]にて、対象の監視項目のステータスは"有効"となっております。エラー欄に"Not supported by ZABBIX agent"は表示されておりません。

[監視データ]-[最新データ]にて、対象の監視項目の右端にある[ヒストリ]をクリックし、最新500個の値を表示させても何も表示されません。

コメント表示オプション

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

こんにちは。

アイテムの設定は特に問題なさそうです。

Webインターフェースから、該当監視対象の[ホスト]設定の「ホスト名」と、監視対象サーバにインストールしているエージェントのzabbix_agentd.confに設定している「Hostname=」設定は同じホスト名になっているでしょうか。

ユーザー sgym の写真

kodai様

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

[設定]-[ホスト]の「名前欄」と、zabbix_agentd.confに設定している「Hostname=」の記述は同一ホスト名となっております。

また、アイテムのステータスを確認したところ、以下の通り変化していました。
[設定]-[アイテム]にて、対象の監視項目のステータスは"取得不可"、エラー欄に"Not supported by ZABBIX agent"と表示されています。

ユーザー kodai の写真

zabbix_agentd.logやzabbix_server.logには何かエラーは出ていないでしょうか?

アクティブチェックはZABBIXエージェントの方から能動的にZABBIXサーバにデータを送信する仕組みになっています。

NAT越えの環境の場合に、zabbix_agentd.confに記載されているServer=の設定がZABBIXサーバのホスト名/IPアドレスとは異なるために、正常にアクティブチェックが動かないことがあるのですが、そのようなことはないでしょうか。

ユーザー sgym の写真

kodai様

お手数おかけしております。

zabbix_agentd.logやzabbix_server.logには何かエラーは出ていないでしょうか?

zabbix_agentd.logを確認したところ、エラーは見当たりません。以下の通りエージェントは正常に起動していると思われます。
zabbix_agentd started. ZABBIX 1.6.2.
zabbix_agentd collector started
zabbix_agentd listener started
zabbix_agentd listener started
zabbix_agentd listener started
zabbix_agentd active check started [127.0.0.1:10051]

zabbix_server.logを確認したところ、/var/log/messagesのパーミッションが600だった頃には、以下のエラーが出力されておりましたが、644に変更後エラーは出力されておりません。
"Active parameter [log[/var/log/messages]] is not supported by agent on host [ホスト名]"

NAT越えの環境の場合に、zabbix_agentd.confに記載されているServer=の設定がZABBIXサーバのホスト名/IPアドレスとは異なるために、正常にアクティブチェックが動かないことがあるのですが、そのようなことはないでしょうか。

ローカルな環境内での監視ですので問題無い気がするのですが・・・

ユーザー KAZ の写真

sgymさん

また、アイテムのステータスを確認したところ、以下の通り変化していました。
[設定]-[アイテム]にて、対象の監視項目のステータスは"取得不可"、エラー欄に"Not supported by ZABBIX agent"と表示されています。

現在も、エラー欄に"Not supported by ZABBIX agent"と表示されていますか?

ステータス欄が「取得不可」となっている状態だと情報収集がされません。「取得不可」をクリックしてみて下さい。
アイテム設定等が正しければステータス欄が「有効」に変化し、エラー欄のメッセージが非表示になります。

■補足
zabbix1.6.2で言語を日本語で動作させると、ステータス欄のクリックが上手くいかない事象が私の使用している環境で出ています。
上手くいかない場合は個々のアイテムを設定する画面でステータスをドロップダウンから「有効」に変更し保存するか、言語を英語に変更してお試し下さい。

ユーザー sgym の写真

KAZ様

現在も、エラー欄に"Not supported by ZABBIX agent"と表示されていますか?

ステータス欄が「取得不可」となっている状態だと情報収集がされません。「取得不可」をクリックしてみて下さい。
アイテム設定等が正しければステータス欄が「有効」に変化し、エラー欄のメッセージが非表示になります。

[設定]-[アイテム]にて、対象となるアイテムの名前欄の左端にあるチェックボックスにチェックを入れ、画面下部「選択を有効」ボタンを押下し、現在ステータスは「有効」となっております。

何のタイミングで「取得不可」となってしまったのか不明です。

■補足
zabbix1.6.2で言語を日本語で動作させると、ステータス欄のクリックが上手くいかない事象が私の使用している環境で出ています。
上手くいかない場合は個々のアイテムを設定する画面でステータスをドロップダウンから「有効」に変更し保存するか、言語を英語に変更してお試し下さい。

ステータスは既に「有効」となっておりますが、念のため個々のアイテム設定画面でステータスをドロップダウンから「有効」に変更し保存し直しました。

アイテムの更新間隔は30秒に設定しており設定後1時間以上経ちますが、zabbix_agentd.log及びzabbix_server.logにはエラーは出力されておりません。

ユーザー KAZ の写真

sgymさん

何のタイミングで「取得不可」となってしまったのか不明です。

以下のタイミングかと思われます。

zabbix_server.logを確認したところ、/var/log/messagesのパーミッションが600だった頃には、以下のエラーが出力されておりましたが、644に変更後エラーは出力されておりません。

アイテムの更新間隔は30秒に設定しており設定後1時間以上経ちますが、zabbix_agentd.log及びzabbix_server.logにはエラーは出力されておりません。

現時点の状況について確認させて下さい。

(1)データが取得されたかの確認
「Monitoring」-「Latest data」を選択し画面を切り替える。

(2)監視対象の「History」-画面左下の表示期間を操作し表示期間を調節し、messagesにログが出力される時間帯を表示する。

(3)実際にログを出力してみる
下記コマンド等で実際にログを出力し、監視間隔経過後にデータが取得されていないか確認する。
<code>echo "LOG TEST ********** LOG TEST" >> /var/log/messages</code>

ユーザー sgym の写真

KAZ様

現時点の状況について確認させて下さい。

(1)データが取得されたかの確認
「Monitoring」-「Latest data」を選択し画面を切り替える。

(2)監視対象の「History」-画面左下の表示期間を操作し表示期間を調節し、messagesにログが出力される時間帯を表示する。

(3)実際にログを出力してみる
下記コマンド等で実際にログを出力し、監視間隔経過後にデータが取得されていないか確認する。
<code>
echo "LOG TEST ********** LOG TEST" >> /var/log/messages
</code>

(1)[監視データ]-[最新データ]にて、画面右上ドロップダウンより対象のホストを選択

(2)監視対象の「ヒストリ」をクリックし、画面左下の表示期間を以下の通り設定しOKボタンクリック

23 February 2009 11 30
Period 1 Hours

(3)ログを出力
echo "LOG TEST ********** LOG TEST" >> /var/log/messages
view /var/log/messages
/var/log/messagesにて、「LOG TEST ********** LOG TEST」の文言を確認しましが、(2)でのWebインターフェース上には何も表示されておりません。画面右上ドロップダウンより「最新500個の値」を選択しても変化はありません。

ユーザー KAZ の写真

sgymさん

■以下を確認させて下さい。
1)/var/log/messages以外のファイルも同じ状況でしょうか?

2)全てのzabbix_agentdの環境で同じ現象でしょうか?

■御願い
1)zabbix_agentdのログレベルをdebugに変更し、ログを取っていただけませんでしょうか?

ユーザー sgym の写真

KAZ様

1)/var/log/messages以外のファイルも同じ状況でしょうか?

試しに、/var/log/zabbix/zabbix_server.logの監視設定を行ってみましたが、/var/log/messages同様に監視ができておりません。zabbix_server.logのパーミッションは664、所有者及び所有グループは共にzabbixです。

2)全てのzabbix_agentdの環境で同じ現象でしょうか?

他にzabbix_agentdで監視しているホストにつきましては、/var/log/messagesのログ監視ができ、トリガーも正常に動いています。ZABBIXサーバ、エージェントが同一のLinuxサーバにインストールされているマシンのみ、ログ監視ができていない状況です。

1)zabbix_agentdのログレベルをdebugに変更し、ログを取っていただけませんでしょうか?

zabbix_agentdのDebugLevel=4に変更し、ログを出力しました。該当しそうな箇所を貼り付けます。「messages」に関しては出てきませんでしたが、「active checks」に関するエラーが出力されていました。

4523:20090223:175304 In get_min_nextcheck()
4523:20090223:175304 Sleeping for 1 seconds
4522:20090223:175304 Processing request.
4522:20090223:175304 In check_security()
4522:20090223:175304 Requested [net.if.out[eth1,bytes]]
4522:20090223:175304 Sending back [0]
4520:20090223:175304 Processing request.
4520:20090223:175304 In check_security()
4520:20090223:175304 Requested [vfs.fs.size[/opt,pfree]]
4520:20090223:175304 Sending back [90.251998]
4523:20090223:175305 In send_buffer('127.0.0.1','10051')
4523:20090223:175305 Values in the buffer 0 Max 100
4523:20090223:175305 Sleeping for 1 seconds
4521:20090223:175305 Processing request.
4521:20090223:175305 In check_security()
4521:20090223:175305 Requested [net.if.in[eth0,bytes]]
4521:20090223:175305 Sending back [1353357366]
4522:20090223:175203 In check_security()
4522:20090223:175203 Requested [vfs.fs.size[/opt,free]]
4522:20090223:175203 Sending back [123240460]
4520:20090223:175204 Processing request.
4520:20090223:175204 In check_security()
4520:20090223:175204 Requested [net.if.out[eth1,bytes]]
4520:20090223:175204 Sending back [0]
4521:20090223:175204 Processing request.
4521:20090223:175204 In check_security()
4521:20090223:175204 Requested [vfs.fs.size[/opt,pfree]]
4521:20090223:175204 Sending back [90.252042]
4523:20090223:175204 In send_buffer('127.0.0.1','10051')
4523:20090223:175204 Values in the buffer 0 Max 100
4523:20090223:175204 refresh_active_checks('127.0.0.1',10051)
4523:20090223:175204 Get active checks error: Cannot connect to [127.0.0.1:10051] [Connection refused]
4523:20090223:175204 In process_active_checks('127.0.0.1',10051)
4523:20090223:175204 In get_min_nextcheck()
4523:20090223:175204 Sleeping for 1 seconds
4523:20090223:175205 In send_buffer('127.0.0.1','10051')
4523:20090223:175205 Values in the buffer 0 Max 100
4523:20090223:175205 Sleeping for 1 seconds
4522:20090223:175205 Processing request.
4522:20090223:175205 In check_security()
4522:20090223:175205 Requested [net.if.in[eth0,bytes]]
4522:20090223:175205 Sending back [1352341369]
4520:20090223:175205 Processing request.
4520:20090223:175205 In check_security()
4520:20090223:175205 Requested [net.if.out[lo,bytes]]
4520:20090223:175205 Sending back [1373538445]
4521:20090223:175205 Processing request.
4521:20090223:175205 In check_security()
4521:20090223:175205 Requested [vfs.fs.size[/opt,pused]]
4521:20090223:175205 Sending back [9.747958]
4523:20090223:175103 In send_buffer('127.0.0.1','10051')
4523:20090223:175103 Values in the buffer 0 Max 100
4523:20090223:175103 Sleeping for 1 seconds
4520:20090223:175104 Processing request.
4520:20090223:175104 In check_security()
4520:20090223:175104 Requested [net.if.out[eth1,bytes]]
4520:20090223:175104 Sending back [0]
4521:20090223:175104 Processing request.
4521:20090223:175104 In check_security()
4521:20090223:175104 Requested [vfs.fs.size[/opt,pfree]]
4521:20090223:175104 Sending back [90.252092]
4523:20090223:175104 In send_buffer('127.0.0.1','10051')
4523:20090223:175104 Values in the buffer 0 Max 100
4523:20090223:175104 refresh_active_checks('127.0.0.1',10051)
4523:20090223:175104 Get active checks error: Cannot connect to [127.0.0.1:10051] [Connection refused]
4523:20090223:175104 In process_active_checks('127.0.0.1',10051)

ユーザー KAZ の写真

sgymさん

zabbix_agentd.confですが、以下の様に指定していますでしょうか?

<code>
Server=127.0.0.1
ListenIP=127.0.0.1
</code>

■Server={zabbix_serverのIPアドレス}
ローカル方ストではなくzabbix_server.confに設定しているIPアドレスを指定してください。(他のサーバのzabbix_agentd.confと同じにして下さい。)

■ListenIP={zabbix_agentdのIPアドレス}
webフロントエンドのHost設定のIPアドレスと同じでしょうか?
基本的にはローカルホストを使用しない方が良いかと。

ユーザー sgym の写真

KAZ様

zabbix_agentd.confですが、以下の様に指定していますでしょうか?

<code>
Server=127.0.0.1
ListenIP=127.0.0.1
</code>

はい、その通りに指定しています。

■Server={zabbix_serverのIPアドレス}
ローカル方ストではなくzabbix_server.confに設定しているIPアドレスを指定してください。(他のサーバのzabbix_agentd.confと同じにして下さい。)

zabbix_server.confに設定しているIPアドレスではありませんでした。ここが原因だったのですね。

■ListenIP={zabbix_agentdのIPアドレス}
webフロントエンドのHost設定のIPアドレスと同じでしょうか?
基本的にはローカルホストを使用しない方が良いかと。

はい、同じです。

基本的にローカルホストは使用しない方が良いのですね。大変お手数おかけ致しました。

解決に至りました。どうもありがとうございました。

ユーザー sgym の写真

お世話になります。

ログ取得状況を見ると挙動がおかしいので、考えられる原因についてご教授いただきたく存じます。(設定状況等、変わっておりませんので同一スレッドに投稿させていただきました。)

・更新間隔は30秒に設定しているのにタイムスタンプを見ると、30秒毎に取得していない。
・取得してきた値が重複している。

以下、Webフロントで[監視データ]-[最新データ]-[最新500個の値]の表示です。
タイムスタンプ          ローカル時間 ソース 深刻度  値
-----------------------------------------------------------------------------------------------------
[2009.Mar.13 15:07:08] -       -   未分類  Mar 13 12:29:33 zabbix last message repeated 5 times
[2009.Mar.13 15:06:11] -       -   未分類  Mar 13 12:28:25 zabbix last message repeated 2 times
[2009.Mar.13 15:05:17] -       -   未分類  Mar 12 18:59:08 zabbix last message repeated 8 times
[2009.Mar.13 15:04:26] -       -   未分類  Mar 12 18:58:03 zabbix last message repeated 6 times
[2009.Mar.13 15:03:37] -       -   未分類  Mar 12 18:48:53 zabbix last message repeated 8 times
[2009.Mar.13 15:02:52] -       -   未分類  Mar 12 18:47:50 zabbix last message repeated 4 times
[2009.Mar.13 15:02:10] -       -   未分類  Mar 12 17:58:58 zabbix last message repeated 2 times
[2009.Mar.13 15:01:31] -       -   未分類  Mar 12 16:59:12 zabbix last message repeated 2 times
[2009.Mar.13 15:00:55] -       -   未分類  Mar 12 16:39:03 zabbix last message repeated 4 times
[2009.Mar.13 15:00:22] -       -   未分類  Mar 12 16:37:19 zabbix last message repeated 10 times
[2009.Mar.13 14:59:52] -       -   未分類  Mar 12 16:36:12 zabbix last message repeated 2 times
[2009.Mar.13 14:59:39] -       -   未分類  Mar 12 16:37:19 zabbix last message repeated 10 times
[2009.Mar.13 14:59:25] -       -   未分類  Mar 12 16:31:15 zabbix last message repeated 2 times
[2009.Mar.13 14:59:09] -       -   未分類  Mar 12 16:36:12 zabbix last message repeated 2 times
[2009.Mar.13 14:59:01] -       -   未分類  Mar 12 16:29:59 zabbix last message repeated 2 times
[2009.Mar.13 14:58:42] -       -   未分類  Mar 12 16:31:15 zabbix last message repeated 2 times
[2009.Mar.13 14:58:40] -       -   未分類  Mar 12 16:28:54 zabbix last message repeated 10 times
[2009.Mar.13 14:58:22] -       -   未分類  Mar 12 16:27:41 zabbix last message repeated 2 times
[2009.Mar.13 14:58:18] -       -   未分類  Mar 12 16:29:59 zabbix last message repeated 2 times
[2009.Mar.13 14:58:07] -       -   未分類  Mar 12 16:17:25 zabbix last message repeated 8 times
[2009.Mar.13 14:57:57] -       -   未分類  Mar 12 16:28:54 zabbix last message repeated 10 times
[2009.Mar.13 14:57:55] -       -   未分類  Mar 12 16:15:57 zabbix last message repeated 4 times
[2009.Mar.13 14:57:46] -       -   未分類  Mar 12 15:53:26 zabbix last message repeated 10 times
[2009.Mar.13 14:57:40] -       -   未分類  Mar 12 15:52:16 zabbix last message repeated 10 times
[2009.Mar.13 14:57:39] -       -   未分類  Mar 12 16:27:41 zabbix last message repeated 2 times
[2009.Mar.13 14:57:37] -       -   未分類  LOG test ********** LOG test
[2009.Mar.13 14:57:24] -       -   未分類  Mar 12 16:17:25 zabbix last message repeated 8 times
[2009.Mar.13 14:57:12] -       -   未分類  Mar 12 16:15:57 zabbix last message repeated 4 times
[2009.Mar.13 14:57:08] -       -   未分類  Mar 12 16:15:57 zabbix last message repeated 4 times
[2009.Mar.13 14:57:03] -       -   未分類  Mar 12 15:53:26 zabbix last message repeated 10 times
[2009.Mar.13 14:56:59] -       -   未分類  Mar 12 15:53:26 zabbix last message repeated 10 times
[2009.Mar.13 14:56:57] -       -   未分類  Mar 12 15:52:16 zabbix last message repeated 10 times
[2009.Mar.13 14:56:54] -       -   未分類  LOG test ********** LOG test
[2009.Mar.13 14:56:53] -       -   未分類  Mar 12 15:52:16 zabbix last message repeated 10 times
[2009.Mar.13 14:56:50] -       -   未分類  LOG test ********** LOG test
[2009.Mar.13 14:49:38] -       -   未分類  Mar 12 16:39:03 zabbix last message repeated 4 times
[2009.Mar.13 14:49:05] -       -   未分類  Mar 12 16:37:19 zabbix last message repeated 10 times
[2009.Mar.13 14:48:35] -       -   未分類  Mar 12 16:36:12 zabbix last message repeated 2 times
[2009.Mar.13 14:48:08] -       -   未分類  Mar 12 16:31:15 zabbix last message repeated 2 times
[2009.Mar.13 14:47:44] -       -   未分類  Mar 12 16:29:59 zabbix last message repeated 2 times
[2009.Mar.13 14:47:23] -       -   未分類  Mar 12 16:28:54 zabbix last message repeated 10 times
[2009.Mar.13 14:47:05] -       -   未分類  Mar 12 16:27:41 zabbix last message repeated 2 times
[2009.Mar.13 14:46:50] -       -   未分類  Mar 12 16:17:25 zabbix last message repeated 8 times
[2009.Mar.13 14:46:38] -       -   未分類  Mar 12 16:15:57 zabbix last message repeated 4 times
[2009.Mar.13 14:46:29] -       -   未分類  Mar 12 15:53:26 zabbix last message repeated 10 times
[2009.Mar.13 14:46:23] -       -   未分類  Mar 12 15:52:16 zabbix last message repeated 10 times
[2009.Mar.13 14:46:20] -       -   未分類  LOG test ********** LOG test
[2009.Mar.13 14:37:13] -       -   未分類  LOG test ********** LOG test

以下、12日以降の/var/log/messagesの内容です。
Mar 12 11:58:58 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 12 12:14:58 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 12 12:16:21 zabbix last message repeated 3 times
Mar 12 12:31:20 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 12 12:32:21 zabbix last message repeated 4 times
Mar 12 12:58:57 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 12 13:09:00 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 12 13:10:30 zabbix last message repeated 4 times
Mar 12 13:36:37 zabbix last message repeated 2 times
Mar 12 13:37:41 zabbix last message repeated 4 times
Mar 12 13:39:16 zabbix last message repeated 2 times
Mar 12 14:50:13 zabbix last message repeated 2 times
Mar 12 14:51:16 zabbix last message repeated 8 times
Mar 12 14:52:41 zabbix last message repeated 4 times
Mar 12 14:58:02 zabbix last message repeated 4 times
LOG test ********** LOG test
Mar 12 15:52:16 zabbix last message repeated 10 times
Mar 12 15:53:26 zabbix last message repeated 10 times
Mar 12 16:15:57 zabbix last message repeated 4 times
Mar 12 16:17:25 zabbix last message repeated 8 times
Mar 12 16:27:41 zabbix last message repeated 2 times
Mar 12 16:28:54 zabbix last message repeated 10 times
Mar 12 16:29:59 zabbix last message repeated 2 times
Mar 12 16:31:15 zabbix last message repeated 2 times
Mar 12 16:36:12 zabbix last message repeated 2 times
Mar 12 16:37:19 zabbix last message repeated 10 times
Mar 12 16:39:03 zabbix last message repeated 4 times
Mar 12 16:59:12 zabbix last message repeated 2 times
Mar 12 17:58:58 zabbix last message repeated 2 times
Mar 12 18:47:50 zabbix last message repeated 4 times
Mar 12 18:48:53 zabbix last message repeated 8 times
Mar 12 18:58:03 zabbix last message repeated 6 times
Mar 12 18:59:08 zabbix last message repeated 8 times
Mar 13 12:28:25 zabbix last message repeated 2 times
Mar 13 12:29:33 zabbix last message repeated 5 times
Mar 13 13:06:15 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 13 13:18:57 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 13 13:20:01 zabbix last message repeated 5 times
Mar 13 13:35:57 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 13 13:37:18 zabbix last message repeated 5 times
Mar 13 14:06:09 zabbix last message repeated 2 times

ユーザー sgym の写真

自己レスです。

・更新間隔は30秒に設定しているのにタイムスタンプを見ると、30秒毎に取得していない。

log[]パラメータの動きとして、初回のチェックで全データを読み込み、2回目以降前回との差分を読むのですね。

しかし、現状では初回で全データを読み込んでおらず、さらに2回目以降差分データを読み込んでいない動きをしています。

ユーザー kodai の写真

こんにちは。

2009.Mar.13 14:56:50のタイミングから、再度重複して過去のログまで収集してしまっているようですね。

このタイミングで、ログファイルを一旦削除して再作成といった何か関連しそうな作業を行ったということはないでしょうか?

ユーザー sgym の写真

kodai様

2009.Mar.13 14:56:50のタイミングから、再度重複して過去のログまで収集してしまっているようですね。

このタイミングで、ログファイルを一旦削除して再作成といった何か関連しそうな作業を行ったということはないでしょうか?

ログファイルの削除や再作成は行っておりません。

3月17日10:40時点の状況ですが、/var/log/messagesには以下の通り出力されておりますが、
Mar 15 04:03:30 zabbix syslogd 1.4.1: restart.
Mar 17 10:01:30 zabbix avahi-daemon[2562]: Invalid response packet.
Mar 17 10:02:16 zabbix last message repeated 2 times
Mar 17 10:03:36 zabbix last message repeated 2 times

Webフロントエンドにて[監視データ]-[最新データ]を見ると、
タイムスタンプが 2009.Mar.15 04:56:26 から 2009.Mar.15 06:18:08の間に、値「Mar 15 04:03:30 zabbix syslogd 1.4.1: restart.」が182個表示されています。

また、Mar 17 10:01:30以降の値が表示されておりません。

ユーザー kodai の写真

1.6.2で色々試してみたのですが、こちらの環境では同様の問題は再現することができませんでした。

ZABBIXエージェントでDebugLevel=4に設定して何か関連するログが出ていないかなど、より詳細に調査頂けないでしょうか。

ユーザー sgym の写真

kodai様

お手数お掛けしております。

kodaiさんは書きました:
1.6.2で色々試してみたのですが、こちらの環境では同様の問題は再現することができませんでした。

ZABBIXエージェントでDebugLevel=4に設定して何か関連するログが出ていないかなど、より詳細に調査頂けないでしょうか。

Webフロントエンドにてアイテム設定をログ取得1つのみにして、DebugLevel=4で10分間出力させました。アイテム設定値は当初より変更しておりません。以下出力されたzabbix_agentd.logの抜粋です。

〜前略〜

21468:20090319:110051 zabbix_agentd started. ZABBIX 1.6.2.
21468:20090319:110051 cfg: para: [Server] val [IPアドレス]
21468:20090319:110051 cfg: para: [Hostname] val [ZABBIX Server]
21468:20090319:110051 cfg: para: [StartAgents] val [5]
21468:20090319:110051 cfg: para: [DebugLevel] val [4]
21468:20090319:110051 cfg: para: [PidFile] val [/var/run/zabbix/zabbix_agentd.pid]
21468:20090319:110051 cfg: para: [LogFile] val [/var/log/zabbix/zabbix_agentd.log]
21468:20090319:110051 cfg: para: [Timeout] val [3]
21469:20090319:110051 zabbix_agentd collector started
21470:20090319:110051 zabbix_agentd listener started

〜中略〜

21473:20090319:110051 zabbix_agentd active check started [IPアドレス:10051]
21473:20090319:110051 In init_active_metrics()
21473:20090319:110051 In send_buffer('IPアドレス','10051')
21473:20090319:110051 Values in the buffer 0 Max 100
21473:20090319:110051 refresh_active_checks('IPアドレス',10051)
21473:20090319:110054 Sending [{
"request":"active checks",
"host":"ZABBIX Server"}]
21473:20090319:110054 Before read
21473:20090319:110054 Timeout while answering request
21473:20090319:110054 Get active checks error: ZBX_TCP_READ() failed [Interrupted system call]
21473:20090319:110054 In process_active_checks('IPアドレス',10051)
21473:20090319:110054 In get_min_nextcheck()

〜中略〜

21473:20090319:110154 In send_buffer('IPアドレス','10051')
21473:20090319:110154 Values in the buffer 0 Max 100
21473:20090319:110154 refresh_active_checks('IPアドレス,10051)
21473:20090319:110157 Sending [{
"request":"active checks",
"host":"ZABBIX Server"}]
21473:20090319:110157 Before read
21473:20090319:110157 Timeout while answering request
21473:20090319:110157 Get active checks error: ZBX_TCP_READ() failed [Interrupted system call]
21473:20090319:110157 In process_active_checks('IPアドレス',10051)
21473:20090319:110157 In get_min_nextcheck()
21473:20090319:110157 In send_buffer('IPアドレス','10051')
21473:20090319:110157 Values in the buffer 0 Max 100
21473:20090319:110157 Sleeping for 1 seconds

〜中略〜

21473:20090319:110257 refresh_active_checks('IPアドレス',10051)
21473:20090319:110300 Timeout while answering request
21473:20090319:110300 Get active checks error: Cannot connect to [IPアドレス:10051] [Interrupted system call]
21473:20090319:110300 In process_active_checks('IPアドレス',10051)
21473:20090319:110300 In get_min_nextcheck()
21473:20090319:110300 In send_buffer('IPアドレス','10051')
21473:20090319:110300 Values in the buffer 0 Max 100
21473:20090319:110300 Sleeping for 1 seconds

〜後略〜

関係するか分かりませんが、zabbix_server.logには以下のエラーが出力されています。

22138:20090319:111602 Error sending result back
22143:20090319:114241 [Z3005] Query failed: [1205] Lock wait timeout exceeded; try restarting transaction [updateids set nextid=nextid+1 where nodeid=0 and table_name='history_log' and field_name='id']

ユーザー kodai の写真

返信が遅くなってしまいすみません。

ログを拝見したところ、以下のことが見受けられます。

1. ZABBIXエージェントがZABBIXサーバにデータを遅れていない
2. ZABBIXサーバがデータベースに情報を書き込めていない

ZABBIX本家のフォーラムなどを探してみましたが、同じ現象は報告されていないようで、多少関連しそうなのは以下くらいでしょうか。

http://www.zabbix.com/forum/showthread.php?t=10597

とはいえ、一部が書き込めている状況は不可解ですね...。ひとまず思いつく範囲で原因として考えられるのは、

* 何らかの原因でZABBIXサーバがデータベースに書き込みを行えない状況にある。データベースが高負荷になっていたりすることはないでしょうか?MySQL側のログでエラーが出ていないかどうかも確認してみてください。

* ZABBIXエージェント -> ZABBIXサーバの10051番ポートへの通信が行えていない。ネットワーク周りの設定やZABBIXサーバのtrapperプロセスの動作不具合などが原因として考えられます。zabbix_server.confでStartTrapper=の値を絞られていたりするkとはないでしょうか?

その他、ZABBIXサーバを再起動してみる、該当するアイテム設定を一度削除して再作成してみる、なども状況によっては効果があるかもしれません。

ユーザー sgym の写真

kodai様

ご返信ありがとうございます。
こちらこそ返信が遅れてしまい申し訳ございません。

* 何らかの原因でZABBIXサーバがデータベースに書き込みを行えない状況にある。データベースが高負荷になっていたりすることはないでしょうか?MySQL側のログでエラーが出ていないかどうかも確認してみてください。

監視するホストを1つのみにし、アイテム設定をログ取得1つのみに設定して経過を見ましたが、重複してログ取得していました。同条件でホストを替えてみましたが、結果は同じでした。DBの負荷ではないような気がします。

/var/log/mysqld.logを確認しましたが、エラーは特に出力されていないように見えます。

以下mysqld.logの内容です。
mysqld started
InnoDB: Started; log sequence number 38 610826886
[Note] /usr/libexec/mysqld: ready for connections.
Version: '5.0.45' socket: '/var/lib/mysql/mysql.sock' port: 3306 Source distribution

* ZABBIXエージェント -> ZABBIXサーバの10051番ポートへの通信が行えていない。ネットワーク周りの設定やZABBIXサーバのtrapperプロセスの動作不具合などが原因として考えられます。zabbix_server.confでStartTrapper=の値を絞られていたりするkとはないでしょうか?

「zabbix_server.conf」内の「StartTrapper=」はデフォルトの設定「#StartTrappers=5」となっています。

その他、ZABBIXサーバを再起動してみる、該当するアイテム設定を一度削除して再作成してみる、なども状況によっては効果があるかもしれません。

ログ取得のアイテムを削除後に再作成し、ZABBIXサーバを再起動しました。監視している幾つかのサーバは最初の数時間は正常な動作が確認できましたが、重複して取得するようになりました。最初から取得できていないサーバも幾つかある状況です。

■追記
サーバを1.6.2→1.6.3へバージョンアップし、監視対象の端末のエージェントを再起動しました。

重複取得の事象が見られなくなり24時間以上経過しました。このまま静観してみます。