Spread Toolkit で分散ログ (5) syslog とのパフォーマンス比較

実際のところ syslogd でログを取るのと比べてどうなのか比較してみた。

ログ採取マシンは以下のようなスペック。

OS : fedora core 6
CPU : Athlon 64 3200+ (2.0GHz)
RAM : 1GB
HDD : 3w-9500-4LP (SATA RAID-5, 320GB * 4)

Bonnie でベンチマークを取ってみると以下のような数値。3ware の RAID カードを奢ったので、結構速い。

$ Bonnie -s 2047
              -------Sequential Output-------- ---Sequential Input-- --Random--
              -Per Char- --Block--- -Rewrite-- -Per Char- --Block--- --Seeks---
Machine    MB K/sec %CPU K/sec %CPU K/sec %CPU K/sec %CPU K/sec %CPU  /sec %CPU
         2047 40566 95.8 85390 24.2 33999  8.7 38590 81.6 168442 13.2 436.6  0.8

ベンチマークは最初、Apache に Apache Bench で負荷を掛けて計測しようかと思ったのだが、syslog は同じ内容のログが連続すると

last message repeated **** times

として端折る。そのため、同一リクエストを連続して発生させても正しいベンチマークにならない。

ということで、実際のアクセスログを使って以下のようにしてみた。
ログ採取マシンとは別のマシンから

$ perl -n -e 'print; select(undef,undef,undef,0.1) if $.%10==0' access_log \
   | spread_log.pl          # spread の場合
$ perl -n -e 'print; select(undef,undef,undef,0.1) if $.%10==0' access_log \
   | logger -p local1.debug # syslog の場合

を実行。この例だと 10行 print したら 0.1秒 sleep、つまり 100行 / 秒のログが発生している状況をシミュレート。

ログ採取マシンで top コマンドを実行し、io wait を観察すると以下のようになった。

rows/sec	logger + syslogd	spread + spreadlogd
100	10%	0%
300	35%	0〜1%
1000	80%	0〜2%

1000 rows/sec ぐらいになると、syslog では IO 負荷が辛すぎる。
syslogd, spread, spreadlogd の CPU 使用率はせいぜい 2% 程度で、CPU 負荷については全く問題ない。