2013年5月15日水曜日

logrotateってなんじゃ?(pigzで高速ローテート)

大量アクセスがあってログファイルが巨大であったりすると、日々のlogrotateが重くなります。

対象ディレクトリ以下に大量のファイルがある場合も時間がかかることがありますが、その場合はローテションの世代数を減らしたり、対象ディレクトリから定期的に退避すれば済むため、ネックになるのは主に圧縮によるものだと思います。

デフォルトではgzipが利用されますが、別の圧縮プログラムを利用することもできます。
圧縮プログラムの選定ですが、基本的に圧縮率の高いプログラムは時間がかかりますし、高速なものは圧縮率が低いものが一般的ですが、例外があります。

gzipなどはシングルコアしか使用しませんが、マルチコアで分散処理する圧縮プログラムだとおなじ圧縮フォーマットでも格段に速くなります。

今回は、その例としてpigzを利用してみます。
pigzは、gzipフォーマットの圧縮をマルチコアで行う高速gzipとして動作します。
pigzで圧縮したファイルはgunzipで解凍できるので、pigzの無い環境にもファイルを持っていくことができます。

それでは早速触ってみます。


複数のCPUがあるマシンでないと意味が無いので、コア数を確認します。
# cat /proc/cpuinfo | grep processor
processor : 0
processor : 1
processor : 2
processor : 3
processor : 4
processor : 5
processor : 6
processor : 7

今回はc1.xlargeですので、8コアです。


pigzをダウンロードして、ビルドします。
cd /usr/local/src/
curl -OL http://www.zlib.net/pigz/pigz-2.3.tar.gz
tar xzvf pigz-2.3.tar.gz
cd pigz-2.3/
make

cc -o pigz pigz.o yarn.o zopfli/deflate.o zopfli/blocksplitter.o zopfli/tree.o zopfli/lz77.o zopfli/cache.o zopfli/hash.o zopfli/util.o zopfli/squeeze.o zopfli/katajainen.o -lpthread -lz
zopfli/tree.o: In function `CalculateEntropy':
tree.c:(.text+0x75): undefined reference to `log'
tree.c:(.text+0x11a): undefined reference to `log'
tree.c:(.text+0x16b): undefined reference to `log'
collect2: ld はステータス 1 で終了しました
make: *** [pigz] エラー 1


なんかエラーが出ました。リンクが張られていないようなので、Makefileで-lmオプションをつけます。
6c6
<  $(CC) -o pigz $^ -lpthread -lz
---
>  $(CC) -o pigz $^ -lpthread -lz -lm




もう一度ビルドします。
# make
cc -o pigz pigz.o yarn.o zopfli/deflate.o zopfli/blocksplitter.o zopfli/tree.o zopfli/lz77.o zopfli/cache.o zopfli/hash.o zopfli/util.o zopfli/squeeze.o zopfli/katajainen.o -lpthread -lz -lm
ln -f pigz unpigz

# ls -l
合計 584
-rw-r--r-- 1  501 games   2630  5月 16 03:46 2013 Makefile
-rw-r--r-- 1 root root    2626  5月 16 03:46 2013 Makefile.org
-rw-r--r-- 1  501 games   2188  7月 29 05:37 2012 README
-rwxr-xr-x 2 root root  128382  5月 16 03:46 2013 pigz
-rw-r--r-- 1  501 games   4836  3月  4 15:24 2013 pigz.1
-rw-r--r-- 1  501 games 140762  3月  4 16:42 2013 pigz.c
-rw-r--r-- 1 root root  115496  5月 15 04:17 2013 pigz.o
-rw-r--r-- 1  501 games   8758  3月  4 15:24 2013 pigz.pdf
-rw-r--r-- 1  501 games    947  7月 29 05:37 2012 pigz.spec
-rwxr-xr-x 2 root root  128382  5月 16 03:46 2013 unpigz
-rw-r--r-- 1  501 games  11079  1月 14 07:56 2012 yarn.c
-rw-r--r-- 1  501 games   6358  1月 14 07:56 2012 yarn.h
-rw-r--r-- 1 root root   11624  5月 15 04:17 2013 yarn.o
drwxr-xr-x 2  501 games   4096  5月 15 04:17 2013 zopfli



pigzとunpigzが出力されていたら成功です。
この2つのプログラムをパスの通っているところに置きます。
cp pigz /usr/local/bin/
cp unpigz /usr/local/bin/



それでは実際に、動かしてみます。
まず1GBのファイルを作ります。
dd if=/dev/zero of=test.log bs=1024 count=1024000

# ls -lh
合計 1001M
-rw-r--r-- 1 root root 1000M  5月 15 05:02 2013 test.log




そして、gzipでの圧縮/非圧縮と、pigzでの圧縮/非圧縮で時間とCPU使用率を見てみます。
# time gzip test.log

real 0m11.084s
user 0m10.407s
sys 0m0.673s

# top
Cpu0  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu1  : 97.3%us,  2.7%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu2  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu3  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu4  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu5  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu6  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu7  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

------------------------------------------------------------------------------------------
# time gunzip test.log.gz

real 0m23.668s
user 0m7.032s
sys 0m1.174s

# top
Cpu0  : 83.6%us, 15.8%sy,  0.0%ni,  0.0%id,  0.3%wa,  0.0%hi,  0.0%si,  0.3%st
Cpu1  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu2  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu3  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu4  :  0.0%us,  0.3%sy,  0.0%ni, 99.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu5  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu6  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu7  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

------------------------------------------------------------------------------------------
# time pigz test.log

real 0m3.025s
user 0m18.781s
sys 0m1.082s

# top
Cpu0  : 51.0%us,  0.7%sy,  0.0%ni, 45.7%id,  0.0%wa,  0.0%hi,  0.0%si,  2.6%st
Cpu1  : 47.8%us,  4.0%sy,  0.0%ni, 48.2%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu2  : 48.2%us, 11.0%sy,  0.0%ni, 40.5%id,  0.0%wa,  0.0%hi,  0.0%si,  0.3%st
Cpu3  : 50.8%us,  0.3%sy,  0.0%ni, 47.8%id,  0.0%wa,  0.0%hi,  0.0%si,  1.0%st
Cpu4  : 49.0%us,  3.3%sy,  0.0%ni, 47.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.7%st
Cpu5  : 50.0%us,  2.0%sy,  0.0%ni, 45.7%id,  0.0%wa,  0.0%hi,  0.0%si,  2.3%st
Cpu6  : 50.3%us,  0.7%sy,  0.0%ni, 48.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.3%st
Cpu7  : 48.3%us,  3.3%sy,  0.0%ni, 48.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.3%st

------------------------------------------------------------------------------------------
# time unpigz test.log.gz

real 0m5.298s
user 0m6.808s
sys 0m1.128s

# top
Cpu0  : 73.8%us,  3.6%sy,  0.0%ni, 21.5%id,  0.0%wa,  0.0%hi,  0.0%si,  1.1%st
Cpu1  : 48.0%us, 18.5%sy,  0.0%ni, 18.9%id, 13.0%wa,  0.0%hi,  0.0%si,  1.6%st
Cpu2  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu3  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu4  :  0.0%us,  0.3%sy,  0.0%ni, 99.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu5  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu6  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu7  :  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st


おお、だいぶ速くなったようです。複数のCPUが使われていることも分かります。

次はこれをlogrotateで利用してみます。
コメント付きの部分が圧縮プログラムの設定になります。
全体的に適用したい場合は、/etc/logrotate.confに記述します。
# cat /etc/logrotate.d/httpd
/var/log/httpd/*log {
    daily
    missingok
    ifempty
    compresscmd /usr/local/bin/pigz               # 圧縮プログラムを指定
    uncompresscmd /usr/local/bin/unpigz       # 解凍プログラムを指定
    compressext .gz                                           # 圧縮ファイル拡張子を指定
    sharedscripts
    postrotate
        /sbin/service httpd reload > /dev/null 2>/dev/null || true
    endscript
}


httpdのログファイルを作って、時刻をローテーションの時間に合わせます。
dd if=/dev/zero of=/var/log/httpd/access_log bs=1024 count=1024000
date -s "2013/05/14 03:00:00"


しばらくすると、きちんとローテーションされていることがわかります。
# ls -l /var/log/httpd/
合計 1160
-rw-r--r-- 1 root root       0  5月 16 03:11 2013 access_log
-rw-r--r-- 1 root root 1176015  5月 16 03:11 2013 access_log-20130516.gz
-rw-r--r-- 1 root root     245  5月 16 03:11 2013 error_log
-rw-r--r-- 1 root root     294  5月 16 03:11 2013 error_log-20130516.gz


マルチコア環境に限りますが、これでローテーションが軽くなります。
以上です。