2010/02/02

keepalived, lighttpdのログ出力

前回のWebクラスタの投稿で、keepalivedとlighttpdの挙動を確認する必要がありました。 その時に気がついた事をまとめていきます。

keepalivedのログ出力機構

マニュアルによれば基本的なロギングとしてsyslogが使われています。 デフォルトではfacilityとしてdaemonが使われていて、debianであれば/var/log/daemon.logに出力するよう/etc/rsyslog.confに記述されているはずです。

keepaliedとsyslogについて

でもなぜか/var/log/messagesにkeepalived関連のログが出力されて、/var/log/daemon.logにはそのログが出力されていなかったんですよね。

実際に/etc/rsyslog.confにlocal1からlocal7までのログを出力するよう設定を追加し、立ち上げ直してみます。先頭に近いところに設定を追加して全てのログを出力させます。

/etc/rsyslog.confの設定追加部分抜粋

...
#### RULES ####
###############
local1.*        -/var/log/local1.log
local2.*        -/var/log/local2.log
local3.*        -/var/log/local3.log
local4.*        -/var/log/local4.log
local5.*        -/var/log/local5.log
local6.*        -/var/log/local6.log
local7.*        -/var/log/local7.log
...
$ sudo /etc/init.d/rsyslog restart

再起動後に増加したファイルリスト

...
-rw-r----- 1 root        adm            0 2010-02-02 11:29 local7.log
-rw-r----- 1 root        adm            0 2010-02-02 11:29 local6.log
-rw-r----- 1 root        adm            0 2010-02-02 11:29 local5.log
-rw-r----- 1 root        adm            0 2010-02-02 11:29 local4.log
-rw-r----- 1 root        adm            0 2010-02-02 11:29 local3.log
-rw-r----- 1 root        adm         7486 2010-02-02 12:00 daemon.log
-rw-r----- 1 root        adm         1812 2010-02-02 12:16 local2.log
-rw-r----- 1 root        adm       399033 2010-02-02 12:16 messages
-rw-r----- 1 root        adm         2122 2010-02-02 12:16 local1.log
-rw-r----- 1 root        adm        20873 2010-02-02 12:17 auth.log

実際にはlocal1.logとlocal2.logファイルにkeepalived関連の出力が記録されています。 最新のkeepalivedのgitリポジトリをみると、次のようなコードになっています。

keepalived/vrrp/vrrp_daemon.cから抜粋

/* Opening local VRRP syslog channel */
openlog(PROG_VRRP, LOG_PID | (debug & 1) ? LOG_CONS : 0,
        (log_facility==LOG_DAEMON) ? LOG_LOCAL1 : log_facility);

keepalived/check/check_daemon.cから抜粋

/* Opening local CHECK syslog channel */
openlog(PROG_CHECK, LOG_PID | (debug & 1) ? LOG_CONS : 0, 
        (log_facility==LOG_DAEMON) ? LOG_LOCAL2 : log_facility);

つまり明示的にオプションでsyslogのfacilityとしてLOG_LOCAL1〜7のいずれかを指定すれば、全てのログがそこに出力されます。 しかしデフォルトでは通常のログはLOG_DAEMONに流れ、VRRPとヘルスチェックのログはLOG_LOCAL1、LOG_LOCAL2に分割されて出力されることになっています。

調べてみるとkeepalived-1.1.3で、facility変更のオプションが導入される以前は、固定的にLOG_DAEMON, LOG_LOCAL1, LOG_LOCAL2に各ログが出力されていたようです。 そのため互換性のために、明示的にfacilityを指定しない限りはこのような動きになっているのでしょう。

keepalivedの詳細なログ出力について

オプションに-Dあるいは--log-detailを指定すると、詳細なログを出力するようになります。

debian lennyでこの指定をしようとすると、/etc/init.d/keepalivedを直接編集する必要があります。 本来は/etc/default/keepalivedあたりを作って制御するのがシンプルですよね…。

修正後のkeepalivedスクリプトのdiff出力

diff -u /etc/init.d/keepalived.20100202 /etc/init.d/keepalived
--- /etc/init.d/keepalived.20100202	2010-02-02 11:57:23.000000000 +0900
+++ /etc/init.d/keepalived	2010-02-02 11:58:05.000000000 +0900
@@ -35,7 +35,7 @@
        		test -e $file && test ! -L $file && rm $file
 	done
 	if start-stop-daemon --start --quiet --pidfile /var/run/$NAME.pid \
-               --exec $DAEMON; then
+               --exec $DAEMON -- -D; then
 		log_end_msg 0
 	else
 		log_end_msg 1
@@ -66,7 +66,7 @@
 		/var/run/$NAME.pid --exec $DAEMON
        sleep 1
        if start-stop-daemon --start --quiet --pidfile \
-               /var/run/$NAME.pid --exec $DAEMON; then
+               /var/run/$NAME.pid --exec $DAEMON -- -D; then
 	       log_end_msg 0
 	else
 		log_end_msg 1

ここまでやってもスタンバイ側のログ出力には、ほとんど変化がありません。

出力されるdetailログ

detail(詳細)ログとはいっても、実際には限られた局面だけでログが出力されます。 内部ではdebug変数の6bit目を立てますが(debug |= 32)、これを参照しているのは、ほぼ全てがVRRP関連の処理です。

このオプションで追加されるメッセージは次の通りです。

  • "Netlink reflector reports IP %s %s" from check_api.c
  • "VRRP sockpool: [ifindex(%d), proto(%d), fd(%d,%d)]" from vrrp_scheduler.c
  • "VRRP_Instance(%s) %s protocol %s" from vrrp.c
  • "VRRP_Instance(%s) %s protocol Virtual Routes" from vrrp.c
  • "VRRP_Instance(%s) Sending gratuitous ARPs " from vrrp.c

このオプションを有効にしても、それほど有効なログは取れそうにはありません。 いずれにしてもLOG_ERRなどのクリティカルなログは出力されて、このオプションはそういう状況の助けにはあまりならないと思いました。

まぁこの手のdaemonがやたらログを出力しても困るんですけどね、

virtual_router_idの範囲について

daemon.logに出力されたエラーログ

Feb  2 12:55:50 vmkeepad01b Keepalived: Starting VRRP child process, pid=4424
Feb  2 12:55:54 vmkeepad01b Keepalived: VRRP child process(4424) died: Respawning
Feb  2 12:55:54 vmkeepad01b Keepalived: Remove a zombie pid file /var/run/vrrp.pid

lighttpdのログ出力

標準ではエラーログの出力だけしか準備されていないので、通常はmod_accesslogを含めると思います。個人的に使うだけであれば、知りたいアクセス情報の収拾はGoogle Analysis辺りにまかせてしまい、サーバのログを収拾する意味は不正アクセスの兆候を知るとか、個人レベルでは必須ではないのかもしれません。

Proxyモジュールのログ出力

lighttpdが標準装備しているproxyモジュールのデバッグには一つのオプションだけが使えますが、access.logから読み取れる以上の情報は得られません。

/etc/lighttpd/conf-enabled/10-proxy.confファイル抜粋

...
proxy.debug = 1
...

デバッグ用メッセージはerror.logファイルに出力されます。

ここで2台あるapache2を両方とも停止させると次のようなログが出力されます。

apache2停止時のerror.logの出力例

2010-02-02 10:07:49: (mod_proxy.c.1080) proxy - start 
2010-02-02 10:07:49: (mod_proxy.c.1118) proxy - ext found 
2010-02-02 10:07:49: (mod_proxy.c.1161) proxy - used fair balancing 
2010-02-02 10:07:49: (mod_proxy.c.1242) proxy - found a host 10.0.30.1 80 
2010-02-02 10:07:49: (mod_proxy.c.377) connect delayed: 7 
2010-02-02 10:07:49: (mod_proxy.c.1015) proxy: fdevent-hup 1

ほとんどaccess.logでも似たような状況が判断できるので、監視系をどう構築するのかにも寄りますが、これはmod_proxy.cの開発以外には使えない印象を受けました。

まとめ

lighttpdは小さく設定ファイルを作成して必要最小限の機能だけを使って、ProxyサーバやFastCGIサーバを分割して作成する事ができると思います。 もし1台でいろいろやる必要があればapacheを使うと思いますが、lighttpdみたいなものも使ってみて自分のツールの中に入れておくのはおもしろいと思います。

時刻: 15:11

ラベル: ,

0 件のコメント:

コメントを投稿

登録: コメントの投稿 (Atom)