KAZさん、ありがとうございます。

確認ですが、
＞Zabbixエージェントは監視間隔で読込バッファ(MaxLinesPerSecond×4)にログを読み込みます。(デフォルト:400行)
こういう理解で合ってますか？
・バッファに読んだ後でアイテムで指定したパターンにマッチするかを判定する
・マッチしたものを送信するので、必ず400行送信されるわけではなく、最大で400行送信される可能性がある
・更新間隔が60秒であれば「1秒当たり100行」は「60秒当たり6000行」なので、400行あっても全部送信できる
・更新間隔が1秒なら、400行あったら（MaxLinesPerSecond が 100 なので）最初の100行だけを送信して、残りは次回に回される

とにかく、MaxLinesPerSecond と更新間隔を変更して試してみました。

ログに15000行書き込んだときに以下のスクリプトを実行して直接 history_log テーブルを見た結果を添付します。
まとめは後ろに書きますが、この結果から何か分かることはありますでしょうか？
------------------------------
#!/bin/sh
sql="select clock,ns,value from history_log where value like '%xxx%' order by clock desc, ns desc limit 1"
while [ 1 ]; do
now=`date +%H:%M:%S`
result=`echo $sql | mysql -u root --skip-column-names zabbix`
echo [$now] $result
sleep 1
done
------------------------------
最初の投稿でも書きましたが、一応出力の見方を例で書いておきます。
例：[14:50:44] 1420695923 699563968 14:45:10.003028 (13494) xxx
　　[14:50:44] → 実行した時刻（date コマンドの結果※）
　　1420695923 → clock の値（Zabbix サーバーが処理した時刻？）
　　699563968 → ns の値
　　14:45:10.003028 → 【ログの内容の先頭部分】ログを記録した時刻
　　(13494) → 【ログの内容の続き】何行目のログか
　　 xxx → 【ログの内容の続き】固定

※sleep 1 としていますが、SQL の実行に時間がかかっているためか、必ずしも 1 秒ずつ大きくなるのではなく、2 秒大きくなることもあります。

以下、結果のまとめです。

■MaxLinesPerSecond 100、更新間隔 60
最初の書き込み 16:10:14
最後の書き込み 16:16:29
→書き込みに要した時間は 6分15秒

clock がほぼ同じもの（1420701011,1420701012）が6000行書き込まれ、
その後 clock が約60増えたもの（1420701072）が6000行書き込まれ（たぶん）、
さらに clock が約60増えたもの（1420701132）が3000行書き込まれていました。
→clock 60秒で6000行（これは MaxLinesPerSecond(100) * 60 と同じ）

■MaxLinesPerSecond 1000、更新間隔 60
最初の書き込み 16:21:47
最後の書き込み 16:27:58
→書き込みに要した時間は 6分11秒

15000行全ての clock が同じでした。
→clock 60秒で MaxLinesPerSecond(1000) * 60 = 60000行？

■MaxLinesPerSecond 100、更新間隔 1
最初の書き込み 15:54:01
最後の書き込み 16:00:25
→書き込みに要した時間は 6分24秒

clock は少しずつ大きくなっています。
全体で見ると、5行目で 1420700041、15000行目で 1420700190 。
約150秒大きくなっています。
→だいたい clock 1秒当たり100行（これは MaxLinesPerSecond と同じ）

■MaxLinesPerSecond 1000、更新間隔 1
最初の書き込み 14:45:10
最後の書き込み 16:27:58
→書き込みに要した時間は 6分11秒

clock が同じものは、だいたい1000行ぐらいずつ続いています。
全体で見ても、2行目で 1420695910、15000行目で 1420695924 。
約15秒大きくなっています。
→だいたい clock 1秒当たり1000行（これは MaxLinesPerSecond と同じ）

■その他
＞ログ監視アイテムが１つなら、更新間隔60秒で400行が送信されます。
＞なので、読込が遅いようでしたら、MaxLinesPerSecondを増加させると1回のログ取得量が上がります。
とのことですが、MaxLinesPerSecond を増やしたり更新間隔を 1 にしたりしても、
ログを書き終わるまでにかかる時間はそれほど変化がありませんでした。
15000行で6分強なので、60秒当たりだと2500行弱ということになり、400行よりは多くなります。

実時間ではなく clock で見ると、更新間隔60秒の場合は1分経過ごとに (MaxLinesPerSecond * 60) 行ほど記録されていました。

そもそも clock （と ns）の値は Zabbix サーバーで処理した時刻と思っているのですが、これは正しいですか？

またしても質問ばかりですが、よろしくお願いします。

• table-value.txt (49.88 KB)

こんにちは。

tcpdump とってみました。
結果を添付します（ホスト名部分は xxxxx に変えています）。

設定を再度書いておきます。
　　innodb_buffer_pool_size=512M
　　innodb_log_file_size=64M
　　InnoDB Plugin 未使用
　　barrier=0
　　HistoryCacheSize 64M、HistoryTextCacheSize 64M
　　BufferSize 10000、MaxLinesPerSecond 1000、更新間隔 1
＃mysql.status[Bytes_sent] は戻っています。

何もせずに tcpdump の出力を見ていると、普段は2分おきに14パケットずつ何らかの通信をしているようです。

15000行のログを書き込んで、例のシェルスクリプトで history_log のデータを表示しながら眺めていると、書き込み開始が 11:27:28 、終了が 11:34:06 で、かかった時間は6分38秒でした。

その前後の tcpdump を見ると、何回かに分けて通信しているようでした。
左から順に、一連の通信の時刻、直前との時間差、パケット数 です。
11:26:27.868266～11:26:27.869358　-　　14　　(1)
11:27:23.878719～11:27:23.878984　56秒　14　　(2)
11:27:28.991972～11:27:28.994151　5秒　24　　(3)
11:27:29.066524～11:27:29.066606　1秒　5　　　(4)
11:27:33.381343～11:27:33.441521　4秒　51　　(5)
11:27:38.551889～11:27:38.626595　5秒　94　　(6)
11:27:43.644239～11:27:43.659578　5秒　34　　(7)
11:28:27.666787～11:28:27.667556　44秒　14　　(8)
11:30:27.684194～11:30:27.685069　2分　14　　(9)
11:32:27.702030～11:32:27.702944　2分　14　　(10)
11:34:27.720597～11:34:27.721682　2分　14　　(11)
11:36:27.742698～11:36:27.743913　2分　14　　(12)

想像ですが、(1) は普段の通信、(2) はデータ送信前の準備か何か？、(3)～(7) がログ監視のデータ送信、(8) で以降がまた普段の通信ではないかと思います（(2)～(8) の時間差を足してみると 120 になるので）。
この想像が正しいなら、エージェントからサーバーへのデータ送信は30秒弱で終わっているわけで、サーバー側で遅くなっているということになります。

zabbix_server.conf で DebugLevel=4 にすると、何か分かりますかね？
ログのこの辺に注目して見たらいいとかあればお願いします。
＃ただ、ログは膨大な量になるだろうから、人間の目で追いきれるかは疑問ですが。

• table-value4.txt (58.91 KB)