技術/Java/Solaris10のサービス管理とLog4j-syslogd

• [ Prev ]
• [ Next ]
• [ 技術 ]

お仕事で、Javaからsyslogdにログ出力する必要が生じました。しかも、Solaris上のsyslogです。
Log4jのAppenderで、syslogのプロトコルを用いてネットワーク接続で出力するSyslogAppenderがあるとの事なので、Solaris10もどうにかインストールできましたので試してみました。

• 実験用Javaソース
  • test.log4j.SyslogSample.java
  • log4j.properties
• 実験用Solaris10+syslogd環境整備
  • syslogd(というよりサービス)の再起動
    • 起動中のサービスの一覧
    • syslogの所属するサービスは何か？
    • プロセス名からサービス名(というのか？)を取得してみる。
    • manページに載っている場合もある。
    • サービスの状態と詳細を確認する。
    • syslogd再起動成功
  • ミスその１
  • ミスその２
  • syslogdで外部接続を許可する。
  • 成功
• Log4j + syslogd(Solaris10)
  • リモートのJavaより、syslogdに飛ばす。
  • ローカルのJavaより、syslogdを飛ばす。
• 結論

実験用Javaソース

log4j-1.2.13.jarを使用した。

test.log4j.SyslogSample.java

package test.log4j;

import org.apache.log4j.Logger;

public class SyslogSample {

	public static void main(String[] args) {

		Logger logger = Logger.getLogger("syslog");
		logger.debug("--debug--");
		logger.info("--info--");
		logger.warn("--warn--");
		logger.error("--error--");
		logger.fatal("--fatal--");
	}
}

log4j.properties

log4j.appender.syslog=org.apache.log4j.net.SyslogAppender
log4j.appender.syslog.Facility=local5
log4j.appender.syslog.SyslogHost=192.168.250.50
log4j.appender.syslog.FacilityPrinting=true
log4j.appender.syslog.layout=org.apache.log4j.PatternLayout
log4j.appender.syslog.layout.ConversionPattern=AA%5p %c{1} - %m%n
log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.rootLogger=console, syslog

実験用Solaris10+syslogd環境整備

Solaris上でのsyslog設定やサービスの再起動は初めてだったので、色々と試行錯誤になってしまった。
ちなみに、ローカルでの確認はloggerコマンドを用いて次のようにした。

logger -p local5.notice -t HOGE abcdefg

syslogd(というよりサービス)の再起動

Solaris10では、"SMF(Service Management Facility)という機能により、様々なサービスの起動・停止・再起動・依存関係を統合して管理できるようになった。今回、設定ファイル変更に伴う再起動を行うsyslogdも、SMFを通じて再起動をする。

起動中のサービスの一覧

[root@basara /]# svcs
STATE          STIME    FMRI
legacy_run     19:21:23 lrc:/etc/rcS_d/S50sk98sol
legacy_run     19:22:23 lrc:/etc/rc2_d/S10lu
...
online         22:21:37 svc:/system/system-log:default
offline        19:21:08 svc:/application/print/ipp-listener:default
offline        19:22:12 svc:/application/print/rfc1179:default

syslogの所属するサービスは何か？

通常なら次のコマンドであるプロセスを対象としているサービス名を取得できる。

[root@basara /]# svcs -p sendmail
STATE          STIME    FMRI
online         19:22:23 svc:/network/smtp:sendmail
               19:22:23      376 sendmail
               19:22:23      378 sendmail

しかし、syslogdに関してはこれが利用できない。

プロセス名からサービス名(というのか？)を取得してみる。

[root@basara /]# svcs -p syslogd
svcs: パターン 'syslogd' がどのインスタンスとも一致しません
STATE          STIME    FMRI

manページに載っている場合もある。

そこで、ふとsyslogdのmanを確認していると・・・

$ man syslogd
...
System Administration Commands                        syslogd(1M)

     svc:/system/system-log:default

    Administrative actions on this service,  such  as  enabling,
    disabling,  or  requesting  restart,  can be performed using
    svcadm(1M). The service's status can be  queried  using  the
    svcs(1) command.

サービスの状態と詳細を確認する。

というわけで、

[root@basara /]# svcs -l system/system-log:default
fmri         svc:/system/system-log:default
name         system log 
有効         true
状態         online
next_state   none
state_time   2006年07月02日 (日) 22時21分37秒
logfile      /var/svc/log/system-system-log:default.log
リスタータ   svc:/system/svc/restarter:default
contract_id  109 
dependency   require_all/none svc:/milestone/sysconfig (online)
dependency   require_all/none svc:/system/filesystem/local (online)
dependency   optional_all/none svc:/system/filesystem/autofs (online)
dependency   require_all/none svc:/milestone/name-services (online)

これがsyslogdのようである。下記参照。

• http://solaris-user.com/solaris10_smf/manual_smf.html

syslogd再起動成功

以上より、次のコマンドでsyslogdを再起動できた。

# svcadm restart system/system-log:default

ミスその１

まず、/etc/syslog.confに次のようなエントリを追加してみた。

local5.* /var/log/log4j.log

以下の点で間違い。

1. レベルに"*"は使用不可。レベル大小によるマッチングがあるのだから、全てを出したいのであれば"debug"を使用する。
2. "facility.level"と、ファイル名との間がスペース。他のエントリを見てみると基本、TAB区切り。

ちなみに先の間違っているエントリを使用すると、次のようなログが/var/adm/messagesに出る。

Jul  2 22:10:06 basara syslogd: line 18: unknown priority name "* /var/log/log4j.log"

ミスその２

ログファイルを作らずに、loggerコマンドなどで試してみたところ、/var/adm/messagesに以下のログが出力された。

Jul  2 22:18:07 basara syslogd: /var/log/log4j.log: ファイルもディレクトリもありません。

そこでtouchで作成してみたところ、まだ上記ログが出る。syslogdを再起動してみたら直った。

syslogdで外部接続を許可する。

次のファイルで、外部接続の許可を制御できる。

/etc/default/syslogd

デフォルトで「LOG_FORMAT_REMOTE=YES」がコメントアウトされており、また、それがデフォルトである。禁止したい場合はNOを設定する。今回はリモートのJavaからの出力を試みるので、デフォルトのママにしておく。

成功

上記の注意点を参考に、syslog.confの変更およびログファイルをtouchにより作成し、syslogdの再起動を行ったところ、loggerコマンドで以下のようなログを出力できた。

# tail /var/log/log4j.log
Jul  2 22:19:20 basara HOGE: [ID 702911 local5.notice] abcdefg

Log4j + syslogd(Solaris10)

リモートのJavaより、syslogdに飛ばす。

以下に、実際に出力された模様を示す。

# (このタイミングでWindows側のJavaからSyslogSampleを実行) 
Message from syslogd@[192.168.250.100.11.180] at Sun Jul  2 22:23:24 2006 ...
[192.168.250.100.11.180] local5:AAFATAL syslog - --fatal--^M

# tail /var/log/log4j.log
Jul  2 22:21:40 basara HOGE: [ID 702911 local5.notice] abcdefg
Jul  2 22:23:24 [192.168.250.100.11.180] local5:AADEBUG syslog - --debug--^M
Jul  2 22:23:24 [192.168.250.100.11.180] local5:AA INFO syslog - --info--^M
Jul  2 22:23:24 [192.168.250.100.11.180] local5:AA WARN syslog - --warn--^M
Jul  2 22:23:24 [192.168.250.100.11.180] local5:AAERROR syslog - --error--^M
Jul  2 22:23:24 [192.168.250.100.11.180] local5:AAFATAL syslog - --fatal--^M

以下の点がローカルのloggerと異なっている。

1. リモートIPが記載される。
2. facilityの表記のみになっている。
3. Windows上のJavaから出力した為か、末尾改行で"^M"が付いてしまっている。
4. loggerコマンドの"-t"オプションに相当するパラメータが無い。

ローカルのJavaより、syslogdを飛ばす。

log4j.propertiesを修正し、SyslogHostを"localhost"にしてSolaris10上で実行してみる。

[msakamoto@basara java]$  java -cp .:./lib/log4j-1.2.13.jar test.log4j.SyslogSample 
Message from syslogd@localhost at Sun Jul  2 22:58:05 2006 ...
localhost local5:AAFATAL syslog - --fatal--

実行側のコンソールに、fatalメッセージが割り込んでいるのが分かる。これは正常である。

# tail /var/log/log4j.log
Jul  2 22:58:05 localhost local5:AADEBUG syslog - --debug--
Jul  2 22:58:05 localhost local5:AA INFO syslog - --info--
Jul  2 22:58:05 localhost local5:AA WARN syslog - --warn--
Jul  2 22:58:05 localhost local5:AAERROR syslog - --error--
Jul  2 22:58:05 localhost local5:AAFATAL syslog - --fatal--

こちらがsyslogdの出力しているログである。"AA"以降がJava側で指定しているメッセージフォーマットである。

やはり、ローカルのloggerとフォーマットが異なる。

結論

Log4jのSyslogAppender経由で出力するsyslogは、ローカルでloggerコマンドにより出力するログ形式とはフォーマットが異なる。

ただし、上記は自分で設定したfacilityに出力した場合であり、今回仕事ではuser.errorで固定で出力する。その場合は、まだ実験していない。

余談だが、この実験を終えた後、「今日一日installからここまでずう～～っと動かしっぱなしだったな」と、風呂にはいるのを兼ねて一旦PCを落とした。
その後再起動し、VMwareからSolaris10を立ち上げたら ネットワークカードの初期化に失敗してるし。

急いでグラフィカルログインから（こういうときがあるから迂闊にコンソールにできない。いや、単にLinuxでいうstartxに該当する手順を知らないだけなんだけど）、svcsを叩いてみたら 見事に network/physical:default が offline になってるし。

あわてて /etc/inet/hosts, ipnodes を確認してみたら localhostだけになってて、自分で指定したホスト名のエントリがいつの間にか消去されてるし。

・・・誰だ？自分じゃないはず。・・・まさか、Sun Studio 11とかそのパッチの影響か・・・？確かにSun Studio 11を入れた頃には一通り環境が整いつつあったので、再起動はかけていない。

とりあえず急いで、対応する.savedファイルを確認してホスト名のエントリを書き戻す。

# svcadm enable -r network/physical:default

をやろうとすると(*1)、maintenanceモードに入っているからと怒られる。
ん？ひょっとして

# svcadm reflesh network/physical:default

したのがまずかったか？もう一度svcsしてみたら確かに"maintenance"と表示されてしまっている。

# svcadm clear network/physical:default

したらmaintenanceモードが消えたので、もう一度 enable してみる。

これで、ようやく"online"になってくれた・・・。念のため再起動かけてみると、無事指定しているIPアドレスが取得できたようで、SSHからもログインできた。

あ～～・・・焦った・・・。

• [ Prev ]
• [ Next ]
• [ 技術 ]