外部チェックで1分以上のキューが滞留する原因について

お世話になります

下記の環境で、色々とチューニングしたのですが、
1分以上のキュー滞留が掃けません。
(キューの状態は添付しました。)
ボトルネックが何であるか分かりますでしょうか?

(解決策は、監視間隔を長くする、監視アイテム数を減らす以外では、
Zabbixサーバのスケールアップかスケールアウトしかないでしょうか?)

■構成
①Zabbixサーバ(1台) -> ②Typeperf用Windowsサーバ(1台) -> ③WindowsXP(2000台)

上記の「②Typeperf用Windowsサーバ」にZabbixエージェントを5本インストールしてあります。
(複数インストールした理由は、StartAgentsパラメータの上限が62で、ZabbixサーバからStartPollers(500)に対して、StartAgentsの数(62)が少なく、ボトルネックになると考えこのようにしました。)
ZabbixServerにスクリプトを置いて、スクリプト内部でzabbix_getを使って、②のサーバのZabbixエージェントへUserParameterに設定してある、Typeperfコマンドで
お客様のWindowsXPのリソースを取得しています。
typeperfコマンドの実行には1回あたり、約1.5秒かかります。(コマンドをラップしているスクリプトの実行には、合計1.6秒ほどです)
スクリプトでzabbix_getを実行した結果をzabbix_senderで振り分けながら送信しています。
外部チェックは、1ホストごとに1回だけ実行しています。
外部チェックは、1分間隔です。まずは間隔を長くしたり、監視ホストを減らしたりせずに対応できないかを確認したいです。
(ホスト減らせばキューが減ることは確認済みです。)

※ZabbixのperfCounterは、要件上使いません。

※Windowsサーバ側のCPU、メモリ負荷は、問題ありませんでした。

■Zabbix動作環境
OS:RedHat5.4
zabbix:v1.8
Mysql:5.0.77

メモリ:8GB
CPU:4コア
HDD:90GB

[zabbix_server.conf]
StartPollers=500
StartPollersUnreachable=40
StartTrappers=50
StartPingers=10
CacheSize=100M
HistoryCacheSize=32M
TrendCacheSize=32M
HistoryTextCacheSize=64M
Timeout=30
FixActionMismatch=1

[my.cnf]
default-character-set=utf8
skip-character-set-client-handshake
innodb_file_per_table
innodb_buffer_pool_size=4096M
innodb_log_buffer_size=32M
innodb_log_files_in_group=2
innodb_log_file_size=24M
sort_buffer_size=1M
read_buffer_size=1M
join_buffer_size=256K
read_buffer_size=1M
table_cache=1024
query_cache_size=32M
max_connections = 800
innodb_fast_shutdown=0

■Zabbixサーバの状態
パラメータ 値 詳細
Zabbixサーバの起動 はい localhost:10051
ホスト数 (有効/無効/テンプレート) 4276 2014 / 2247 / 15
アイテム数 (有効/無効/取得不可) 64267 62260 / 2007 / 0
トリガー数 (有効/無効)[障害/不明/正常] 601 0 / 601 [0 / 0 / 0]
ユーザ数 (オンライン) 3 1
1秒あたりの監視項目数(Zabbixサーバの要求パフォーマンス) 450.42 -

■TOPコマンド結果
top - 12:10:00 up 35 days, 13:27, 2 users, load average: 7.54, 7.22, 7.80
Tasks: 901 total, 2 running, 899 sleeping, 0 stopped, 0 zombie
Cpu(s): 25.2%us, 38.8%sy, 0.0%ni, 34.1%id, 1.2%wa, 0.1%hi, 0.7%si, 0.0%st
Mem: 8175316k total, 7579188k used, 596128k free, 78084k buffers
Swap: 8388600k total, 1549104k used, 6839496k free, 2960812k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13057 mysql 15 0 5138m 2.2g 4716 S 22.6 27.6 6:25.52 mysqld
13762 zabbix 15 0 317m 11m 10m S 3.6 0.1 0:03.03 zabbix_server
15943 zabbix 15 0 317m 37m 36m S 1.0 0.5 0:04.68 zabbix_server
13820 zabbix 18 0 371m 9.9m 8204 S 0.7 0.1 0:00.07 zabbix_server
4 root RT -5 0 0 0 S 0.3 0.0 15:58.86 migration/1
8 root RT -5 0 0 0 S 0.3 0.0 15:58.53 migration/3
717 root 10 -5 0 0 0 S 0.3 0.0 31:17.93 kjournald
3247 root 15 0 13276 1744 820 R 0.3 0.0 0:00.07 top

■Zabbixのビジー率とキャッシュフリー
busy icmp pinger process % 0 %
busy poller process % 8.64 %
busy trapper process % 0.14 %
busy housekeeper process % 0 %
busy escalator process % 0 % -
busy timer process % 0 %
busy unreachable poller 0.02 %
history syncer busy 5.29 %

buffer cache free % 89.3 %
history cache free % 99.72 %
history_text cache free % 99 %
trend cache free % 85 %

■Typeperf用Windowsサーバ負荷
\Processor(_Total)\%Processor Time 41.02 %
Memory\Available MBytes 2170 MBytes

[windowsサーバ側のzabbix_agents.conf]
startAgents 62
5つエージェントをインストールし、いずれも62なので、合計620Agents起動していると思います。

最後に、下記の質問の続きです。
http://www.zabbix.jp/node/2808
(zabbixエージェント自体を複数インストールして、検証した結果、解消しなかったので、再度ご相談になります。)

以上、長々と情報を書き、読みづらかったらすみませんが、よろしくお願いいたします。

コメント表示オプション

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

[windowsサーバ側のzabbix_agents.conf]
startAgents 62
5つエージェントをインストールし、いずれも62なので、合計620Agents起動していると思います。

62 x 5だと310ではありませんか?

あと、zabbix_getを実行する相手先のZabbixエージェントへのリク
エストの分散はどのように実現されているのでしょうか。
一部のエージェントに処理時間も含めて要求が偏ってしまっていた
りしませんか?

それと、busy率があまり高くないので今回の問題の対策として効果
はあまり期待できませんが、zabbix_senderを多く利用する場合、
StartTrappersの値をもう少し増やしても良いかもしれません。
逆に、

busy poller process % 8.64 %

となっているということは、StartPollersで起動した500個のうち、
50個未満しか働いていない状態のようですので、無駄なプロセスが
多い状態だと思われます。

ロードアベレージが高いのと、使用されているスワップのサイズが
大きいようにも感じます。
サーバ全体で、利用しているメモリ量を確認して、メモリ配分のバ
ランスを調整することも必要かもしれません。

ということで、

 ・複数起動したZabbixエージェントへの負荷分散ができているか
 ・Trapperプロセス数の増加
 ・Zabbixサーバを稼働しているサーバ上のメモリ利用状況とその
  配分

あたりを確認してみてはいかがでしょうか?

ユーザー hiroyuki の写真

TNKさん

いつもありがとうございます。

>62 x 5だと310ではありませんか?
失礼しました。その通りです。

>50個未満しか働いていない状態のようですので、無駄なプロセスが多い状態だと思われます。
とりあえず、StartPollersを500から90に変更してみましたが、キューの状態に関しては、ほとんど変わりませんでした。

>・複数起動したZabbixエージェントへの負荷分散ができているか
Zabbixエージェント側では、ポートを分けて起動しており、
Zabbixサーバ側では、スクリプトを分けてポート指定して分散するようにしております。
(グループごとにテンプレートを分けて使用するスクリプトを分けています。)
エージェント側のログレベルを上げて、ログを出して、振り分けられてアクセスされていることを確認済みです。

>・Trapperプロセス数の増加
50 から 100 にしてみましたが、キューの状態に関しては、ほとんど変わりませんでした。

>・Zabbixサーバを稼働しているサーバ上のメモリ利用状況とその配分
Zabbix_server.confのパラメータを変更しつつ、
1.6GB程メモリ使用していたプロセスを停止させ、スワップ領域をクリアしました。
その後、スワップをほぼ使用していない状態になったことを確認し、
キューを見てみましたが、キューの状態は、ほとんど変わりませんでした。

■各プロセスビジー率
busy poller process 47.05 %
busy trapper process 0.06 %
busy housekeeper process 0 %
busy unreachable poller 0.001693
history syncer busy 3.55 %

■TOPコマンド結果
top - 21:41:59 up 35 days, 22:59, 2 users, load average: 7.73, 7.43, 7.22
Tasks: 430 total, 3 running, 427 sleeping, 0 stopped, 0 zombie
Cpu(s): 16.1%us, 37.7%sy, 0.0%ni, 45.6%id, 0.0%wa, 0.0%hi, 0.6%si, 0.0%st
Mem: 8175316k total, 6941784k used, 1233532k free, 73396k buffers
Swap: 8388600k total, 360k used, 8388240k free, 3963312k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
28302 mysql 15 0 5081m 1.9g 4752 S 2.7 24.7 5:23.45 mysqld
6 root RT -5 0 0 0 S 0.3 0.0 17:13.49 migration/2
28370 zabbix 18 0 355m 13m 11m S 0.3 0.2 0:00.24 zabbix_server
28428 zabbix 18 0 355m 11m 9888 S 0.3 0.1 0:00.15 zabbix_server
28526 zabbix 18 0 355m 13m 11m S 0.3 0.2 0:00.20 zabbix_server
28634 zabbix 15 0 301m 21m 20m S 0.3 0.3 0:00.43 zabbix_server
28644 zabbix 15 0 301m 20m 19m S 0.3 0.3 0:00.47 zabbix_server

ロードアベレージが高いままの状態でした、
zabbix_get、zabbix_senderの実行で負荷がかかっているかもでしょうか?

ユーザー TNK の写真

>50個未満しか働いていない状態のようですので、無駄なプロセスが多い状態だと思われます。
とりあえず、StartPollersを500から90に変更してみましたが、キューの状態に関しては、ほとんど変わりませんでした。

先に書かせて頂いた通り、StartPollersを減らすのはキューを減らす目的ではなく、
無駄なメモリやCPUの消費を削減するのが主目的で提案させて頂きました。

>・複数起動したZabbixエージェントへの負荷分散ができているか
Zabbixエージェント側では、ポートを分けて起動しており、
Zabbixサーバ側では、スクリプトを分けてポート指定して分散するようにしております。
(グループごとにテンプレートを分けて使用するスクリプトを分けています。)
エージェント側のログレベルを上げて、ログを出して、振り分けられてアクセスされていることを確認済みです。

処理に偏りが無いことも確認されたのですか?

>・Trapperプロセス数の増加
50 から 100 にしてみましたが、キューの状態に関しては、ほとんど変わりませんでした。

そうすると、swap in/outもio waitも無いようですし、やはりまだWindows Serverの
部分がボトルネックになっていると思われます。
Zabbixサーバの負荷状況を見ても、ロードアベレージは高いものの、zabbix_getを
実行して待っている時間が長いような処理も多いでしょうし、CPUのuserが16%程度
でidleも40%以上のようなので、まだ負荷はかけられると思います。

エージェントを5つからさらに増やすことは可能ですか?

ロードアベレージが高いままの状態でした、
zabbix_get、zabbix_senderの実行で負荷がかかっているかもでしょうか?

確かに、外部スクリプトの呼び出しで、外部スクリプト自体を実行するために子プロセス
が起動されて、さらにその処理のなかからzabbix_getを呼び出したりzabbix_senderを
呼び出しているのであれば、プロセスの起動終了が多くなることでの負荷は高くなる
でしょう。
でも、CPUのidleを見ると、まだまだ余裕があるように見受けられます。

ということで、

 ・Zabbixのエージェントへの処理分散に偏りが無いか
 ・さらにZabbixエージェントを別ポートで追加起動して、それに負荷を分散
  できないか

といったあたりを確認してみて頂けませんでしょうか。

ユーザー hiroyuki の写真

TNKさん

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

 ・Zabbixのエージェントへの処理分散に偏りが無いか
 ・さらにZabbixエージェントを別ポートで追加起動して、それに負荷を分散できないか

確認したところ、1分あたり、各エージェントで140~190リクエストを受けていました。

すみません、前回の投稿(2014/07/10 - 20:52)で、記載漏れだったのですが、
すでに、エージェントを別ポートで5本から10本にしてあります。
それでキューは変化ありませんでした。

さらに上げてみたほうがよいでしょうか?

ちなみに、1分間隔で1エージェントあたり、200ホスト分のアクセス(200回zabbix_getのリクエストを受ける)するはずなのですが、
上述した通り、エージェント側ログを見ると、1分あたり、1エージェントで140~190リクエストを受けていました。
200リクエスト分ログが出力されるかと思ったのですが、こんなもんなのでしょうか。

ユーザー TNK の写真

200リクエスト分ログが出力されるかと思ったのですが、こんなもんなのでしょうか。

単純計算であれば、ご自身でも書かれている通り、1エージェント
あたり200程度になるとは思いますが、何らかの理由で処理がつま
ってしまっているところがあるのでしょう。

とはいえ、Zabbixサーバ側のリトライ処理に問題があるのか、それ
ともWindows Serverやその上のZabbixエージェントに問題があるか
を特定できるだけの情報がない状態です。

すでにエージェントは10個起動しているということですが、Zabbix
サーバを稼働させているサーバ機器自体の負荷には、もう少し余裕
があると思われるので、もう少し並列に処理させるだけの余裕はあ
ると思うのですが、エージェントを5個から10個にあげても変化が
なかったのですよね?

そうすると、これ以上エージェントを増やしてもあまり改善は望め
なさそうです。
Windows Serverの負荷状況は問題ないとのことでしたが、何らかの
ログがでていないか再度Zabbixサーバ側、エージェント側両方とも
確認してみて頂けませんか?
Zabbixのログだけではなく、Windowsのイベントビューア上も確認
してみてください。

あともう一つ、可能であればですが、中継するWindows Serverを一
時的にでも増やして試してみるということは可能でしょうか?

もうちょっと、ディスクのI/Oが多かったり、CPUのuserの割合が多
かったりするような場合であれば、Zabbixのバージョンアップで改
善することも予想されるのですが、今回の問題は、時間のかかる値
取得処理が特定のエージェントに集中するような場合に発生する問
題のようなので、バージョンアップしても改善するとはなかなか言
い切れないところです。

ただ、Zabbix 1.8は、今年の11月でサポートが切れてしまうので、
それ以降、不具合修正や脆弱性対応などもZabbix SIAからリリース
されないようです。
継続してZabbixを利用されるのであれば、どこかのタイミングでバ
ージョンアップすることも検討しておいた方が良いと思います。

ご参考:Zabbixのライフサイクルとリリースポリシー
http://www.zabbix.com/life_cycle_and_release_policy.php

ユーザー TNK の写真

すみません。あともう一つ。

外部スクリプトからzabbix_getを呼び出す部分で、呼び出しに
失敗していたりしませんか?
例えば、エージェントから接続を拒否されたりタイムアウトが
発生したりしていないかも確認してみていただけませんか?

ユーザー hiroyuki の写真

TNKさん

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

エージェントを5個から10個にあげても変化がなかったのですよね?

はい、変化ありませんでした。

ログがでていないか再度Zabbixサーバ側、エージェント側両方とも確認してみて頂けませんか?
Zabbixのログだけではなく、Windowsのイベントビューア上も確認
してみてください。

再度、Zabbixサーバ側、エージェント側、Windowsのシステムログ確認してみましたが、変なログはありませんでした。

可能であればですが、中継するWindows Serverを一時的にでも増やして試してみるということは可能でしょうか?

やりたいところですが、
Windows Server増やした後、ZabbixサーバからWindowsサーバへのポートの穴あけ作業に、2週間程かかる為、
できれば、もう少し別の試せることがないか検討したいです。

外部スクリプトからzabbix_getを呼び出す部分で、呼び出しに失敗していたりしませんか?
例えば、エージェントから接続を拒否されたりタイムアウトが発生したりしていないかも確認してみていただけませんか?

zabbix_getの実行結果(標準エラーと標準出力)をログに出すようにして確認してみましたが、
そのようなログはありませんでした。

ユーザー fripper の写真

可能であれば、「エージェント」で設定されているアイテムのうちの一部を
「エージェント(アクティブ)」にしてみるのはいかがでしょうか?

サーバ側がタイミングを見て、エージェント側に問い合わせて答えを得るのではなく
エージェント側がタイミングを見て、値を取得して、サーバへプッシュする、という形になるので
サーバ側の負荷を下げることができます

但し、欠点もあって、エージェントが落ちている等の場合、
「エージェント」だと、サーバが問い合わせた時に応答がないので検知できますが
「アクティブ」だと、エージェントが値を報告してこないだけになるので、
エージェントが落ちたことをサーバが能動的に知れるよう、
一部のアイテムを「エージェント」のまま残す、や「nodataを使ったトリガーでデータ不達を監視」が
必要になってしまいますが‥。

「エージェント」タイプの項目に対して、問い合わせを掛けるのは、サーバ側の「Poller」ですが
「アクティブ」タイプの項目に対するエージェント側からの報告を受け付けるのは、サーバ側の「Trapper」ですので
プロセス数等のチューニングも、勘所が変わってくる点、ご留意ください

ユーザー TNK の写真

fripperさんへ。

ちょっと今回の使い方は特殊なので、Zabbixエージェント(アクテ
ィブ)には簡単に変更できないと思っています。

以前からの経緯も再度確認して頂くとわかるのですが、Zabbixサー
バ上の設定としては外部スクリプトを呼び出すアイテムが登録され
ていて、その外部スクリプト内からzabbix_getコマンドを呼び出し
ている構成のようです。

つまり、zabbix_getコマンドでZabbixエージェントの機能を利用して、
Windows Server上でtypeperfコマンドをリモート実行するために
利用されているようです。

ユーザー zinten の写真

CentOS5.x系だと度々ファイルディスクリプタの問題等が話題になりますがこのあたりとか関係ないですか?
http://mikio.github.io/article/2013/03/02_.html

ユーザー hiroyuki の写真

zintenさん

情報ありがとうございます。

確認してみたところ、上限にはまだ達していないようでした。
# cat /proc/sys/fs/file-nr
2550 0 753832

又、
今まで、外部チェックでスクリプトを実行していたのですが、
試しにZabbixサーバ上にあるZabbixエージェントのUserparameterにスクリプトを設定して実行するようにしたところ、
なぜか、1分のキューが20~50までに減りました。(変更前は、1分のキューが200程度。)
あとは、Typeperf用Windowsサーバを2台にしてみて、残りのキューが掃けないかを試してみます。